You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2016/04/22 18:38:40 UTC
[JENKINS] Lucene-Solr-Tests-5.5-Java8 - Build # 2 - Still Failing
Build: https://builds.apache.org/job/Lucene-Solr-Tests-5.5-Java8/2/
1 tests failed.
FAILED: org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh
Error Message:
Could not find collection : c1
Stack Trace:
org.apache.solr.common.SolrException: Could not find collection : c1
at __randomizedtesting.SeedInfo.seed([94FE21DB598E0A3B:8B44502C89EECCFE]:0)
at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:170)
at org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdate(ZkStateReaderTest.java:136)
at org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh(ZkStateReaderTest.java:42)
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:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
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:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 10638 lines...]
[junit4] Suite: org.apache.solr.cloud.overseer.ZkStateReaderTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.cloud.overseer.ZkStateReaderTest_94FE21DB598E0A3B-001/init-core-data-001
[junit4] 2> 34613 INFO (SUITE-ZkStateReaderTest-seed#[94FE21DB598E0A3B]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false)
[junit4] 2> 34623 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testStateFormatUpdateWithTimeDelayLazy
[junit4] 2> 34624 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 34643 INFO (Thread-55) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 34643 INFO (Thread-55) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 34743 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer start zk server on port:40480
[junit4] 2> 34743 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 34759 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 34935 INFO (zkCallback-27-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@5085aaa6 name:ZooKeeperConnection Watcher:127.0.0.1:40480 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 34935 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 34935 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 34938 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 34948 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 34961 INFO (zkCallback-28-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@60931a41 name:ZooKeeperConnection Watcher:127.0.0.1:40480 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 34961 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 34961 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 34961 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 34972 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 35024 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 35052 INFO (zkCallback-29-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@18b873e8 name:ZooKeeperConnection Watcher:127.0.0.1:40480/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 35052 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 35052 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 35053 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 35054 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections
[junit4] 2> 35063 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 35064 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 35065 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 35066 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 35068 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/c1
[junit4] 2> 35075 INFO (zkCallback-29-thread-2) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating...
[junit4] 2> 35130 INFO (zkCallback-29-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0])
[junit4] 2> 35225 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/c1/state.json
[junit4] 2> 35227 INFO (zkCallback-29-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0])
[junit4] 2> 35769 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:40480 40480
[junit4] 2> 35960 INFO (Thread-55) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:40480 40480
[junit4] 2> 35961 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelayLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testStateFormatUpdateWithTimeDelayLazy
[junit4] 2> 35962 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testStateFormatUpdateWithTimeDelay
[junit4] 2> 35962 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 35969 INFO (Thread-56) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 35969 INFO (Thread-56) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 36071 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer start zk server on port:32797
[junit4] 2> 36071 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 36083 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 36115 INFO (zkCallback-30-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6a4283a6 name:ZooKeeperConnection Watcher:127.0.0.1:32797 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 36115 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 36115 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 36152 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 36155 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 36160 INFO (zkCallback-31-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@4d92efed name:ZooKeeperConnection Watcher:127.0.0.1:32797 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 36160 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 36160 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 36160 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 36171 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 36172 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 36212 INFO (zkCallback-32-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@16d359cd name:ZooKeeperConnection Watcher:127.0.0.1:32797/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 36212 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 36212 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 36213 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 36214 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections
[junit4] 2> 36215 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 36219 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 36220 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 36221 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 36223 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader addZkWatch [c1]
[junit4] 2> 36224 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader Deleting data for [c1]
[junit4] 2> 36224 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/c1
[junit4] 2> 36232 INFO (zkCallback-32-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating...
[junit4] 2> 36248 INFO (zkCallback-32-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0])
[junit4] 2> 36267 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/c1/state.json
[junit4] 2> 36477 INFO (zkCallback-32-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeCreated path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [0])
[junit4] 2> 36481 INFO (zkCallback-32-thread-1) [ ] o.a.s.c.c.ZkStateReader Add data for [c1] ver [0]
[junit4] 2> 36499 INFO (zkCallback-32-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0])
[junit4] 2> 36539 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:32797 32797
[junit4] 2> 36728 INFO (Thread-56) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:32797 32797
[junit4] 2> 36728 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithTimeDelay-seed#[94FE21DB598E0A3B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testStateFormatUpdateWithTimeDelay
[junit4] 2> 36730 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testWatchedCollectionCreation
[junit4] 2> 36730 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 36734 INFO (Thread-57) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 36734 INFO (Thread-57) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 36870 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer start zk server on port:45690
[junit4] 2> 36871 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 36875 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 36891 INFO (zkCallback-33-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@67b19507 name:ZooKeeperConnection Watcher:127.0.0.1:45690 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 36891 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 36891 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 36896 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 36899 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 36951 INFO (zkCallback-34-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2435f583 name:ZooKeeperConnection Watcher:127.0.0.1:45690 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 36955 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 36955 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 36955 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 36969 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 36971 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 37014 INFO (zkCallback-35-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2b9aa234 name:ZooKeeperConnection Watcher:127.0.0.1:45690/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 37019 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 37019 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 37021 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 37024 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections
[junit4] 2> 37026 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 37027 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 37029 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 37030 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 37032 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader addZkWatch [c1]
[junit4] 2> 37032 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader Deleting data for [c1]
[junit4] 2> 37032 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/c1
[junit4] 2> 37036 INFO (zkCallback-35-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating...
[junit4] 2> 37038 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/c1/state.json
[junit4] 2> 37047 INFO (zkCallback-35-thread-1) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeCreated path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [0])
[junit4] 2> 37054 INFO (zkCallback-35-thread-1) [ ] o.a.s.c.c.ZkStateReader Add data for [c1] ver [0]
[junit4] 2> 37125 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:45690 45690
[junit4] 2> 37422 INFO (Thread-57) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:45690 45690
[junit4] 2> 37423 INFO (TEST-ZkStateReaderTest.testWatchedCollectionCreation-seed#[94FE21DB598E0A3B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testWatchedCollectionCreation
[junit4] 2> 37424 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testExternalCollectionWatchedNotWatched
[junit4] 2> 37425 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 37438 INFO (Thread-58) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 37438 INFO (Thread-58) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 37538 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer start zk server on port:52339
[junit4] 2> 37538 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 37608 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 37640 INFO (zkCallback-36-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@3c5c9704 name:ZooKeeperConnection Watcher:127.0.0.1:52339 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 37640 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 37640 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 37642 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 37654 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 37692 INFO (zkCallback-37-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@628257cd name:ZooKeeperConnection Watcher:127.0.0.1:52339 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 37692 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 37693 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 37693 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 37696 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 37701 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 37731 INFO (zkCallback-38-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2cf09c54 name:ZooKeeperConnection Watcher:127.0.0.1:52339/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 37731 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 37731 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 37732 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 37736 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections
[junit4] 2> 37737 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 37738 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 37739 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 37740 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 37757 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/c1
[junit4] 2> 37759 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/c1/state.json
[junit4] 2> 37862 INFO (zkCallback-38-thread-2) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating...
[junit4] 2> 37876 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader addZkWatch [c1]
[junit4] 2> 37876 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader Add data for [c1] ver [0]
[junit4] 2> 37876 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader Removing watch for uninteresting collection [c1]
[junit4] 2> 37878 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:52339 52339
[junit4] 2> 38071 INFO (Thread-58) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:52339 52339
[junit4] 2> 38072 INFO (TEST-ZkStateReaderTest.testExternalCollectionWatchedNotWatched-seed#[94FE21DB598E0A3B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testExternalCollectionWatchedNotWatched
[junit4] 2> 38076 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testStateFormatUpdateWithExplicitRefreshLazy
[junit4] 2> 38077 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 38087 INFO (Thread-59) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 38087 INFO (Thread-59) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 38191 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer start zk server on port:39288
[junit4] 2> 38191 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 38203 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 38227 INFO (zkCallback-39-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@256c228 name:ZooKeeperConnection Watcher:127.0.0.1:39288 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 38231 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 38231 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 38247 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 38247 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 38271 INFO (zkCallback-40-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@36282813 name:ZooKeeperConnection Watcher:127.0.0.1:39288 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 38271 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 38271 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 38271 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 38274 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 38585 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 38592 INFO (zkCallback-41-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@2756c2c name:ZooKeeperConnection Watcher:127.0.0.1:39288/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 38592 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 38592 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 38593 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 38596 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections
[junit4] 2> 38598 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 38599 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 38603 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 38607 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 38608 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/c1
[junit4] 2> 38609 INFO (zkCallback-41-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating...
[junit4] 2> 38612 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/c1/state.json
[junit4] 2> 38627 INFO (zkCallback-41-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0])
[junit4] 2> 38627 WARN (zkCallback-41-thread-2) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /clusterstate.json]
[junit4] 2> 38628 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:39288 39288
[junit4] 2> 38971 INFO (Thread-59) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:39288 39288
[junit4] 2> 38984 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefreshLazy-seed#[94FE21DB598E0A3B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testStateFormatUpdateWithExplicitRefreshLazy
[junit4] 2> 38985 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testStateFormatUpdateWithExplicitRefresh
[junit4] 2> 38986 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 38987 INFO (Thread-60) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 38987 INFO (Thread-60) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 39088 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer start zk server on port:60189
[junit4] 2> 39088 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 39099 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 39136 INFO (zkCallback-42-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@6b24db3c name:ZooKeeperConnection Watcher:127.0.0.1:60189 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 39136 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 39137 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 39152 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 39163 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 39175 INFO (zkCallback-43-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@43fe505b name:ZooKeeperConnection Watcher:127.0.0.1:60189 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 39175 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 39175 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 39175 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /solr
[junit4] 2> 39254 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkCredentialsProvider
[junit4] 2> 39283 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Waiting for client to connect to ZooKeeper
[junit4] 2> 39315 INFO (zkCallback-44-thread-1) [ ] o.a.s.c.c.ConnectionManager Watcher org.apache.solr.common.cloud.ConnectionManager@15e095e4 name:ZooKeeperConnection Watcher:127.0.0.1:60189/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4] 2> 39319 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ConnectionManager Client is connected to ZooKeeper
[junit4] 2> 39319 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient Using default ZkACLProvider
[junit4] 2> 39323 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /live_nodes
[junit4] 2> 39324 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections
[junit4] 2> 39325 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /aliases.json
[junit4] 2> 39326 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /clusterstate.json
[junit4] 2> 39327 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /security.json
[junit4] 2> 39328 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader Updating cluster state from ZooKeeper...
[junit4] 2> 39339 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader addZkWatch [c1]
[junit4] 2> 39340 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.ZkStateReader Deleting data for [c1]
[junit4] 2> 39340 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/c1
[junit4] 2> 39343 INFO (zkCallback-44-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0])
[junit4] 2> 39347 INFO (zkCallback-44-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating...
[junit4] 2> 39351 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/c1/state.json
[junit4] 2> 39355 INFO (zkCallback-44-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeCreated path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [0])
[junit4] 2> 39368 INFO (zkCallback-44-thread-3) [ ] o.a.s.c.c.ZkStateReader Add data for [c1] ver [0]
[junit4] 2> 39399 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:60189 60189
[junit4] 2> 39661 INFO (Thread-60) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:60189 60189
[junit4] 2> 39663 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[94FE21DB598E0A3B]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testStateFormatUpdateWithExplicitRefresh
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ZkStateReaderTest -Dtests.method=testStateFormatUpdateWithExplicitRefresh -Dtests.seed=94FE21DB598E0A3B -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=es-CU -Dtests.timezone=Asia/Ujung_Pandang -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.68s J1 | ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not find collection : c1
[junit4] > at __randomizedtesting.SeedInfo.seed([94FE21DB598E0A3B:8B44502C89EECCFE]:0)
[junit4] > at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:170)
[junit4] > at org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdate(ZkStateReaderTest.java:136)
[junit4] > at org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh(ZkStateReaderTest.java:42)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 39665 INFO (SUITE-ZkStateReaderTest-seed#[94FE21DB598E0A3B]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.cloud.overseer.ZkStateReaderTest_94FE21DB598E0A3B-001
[junit4] 2> Apr 22, 2016 3:48:54 PM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene54): {}, docValues:{}, sim=RandomSimilarity(queryNorm=false,coord=yes): {}, locale=es-CU, timezone=Asia/Ujung_Pandang
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.8.0_74 (64-bit)/cpus=4,threads=1,free=232917552,total=331350016
[junit4] 2> NOTE: All tests run in this JVM: [ZkControllerTest, UniqFieldsUpdateProcessorFactoryTest, TestUseDocValuesAsStored2, TestUniqueKeyFieldResource, TestChildDocTransformer, TestTestInjection, TestPerFieldSimilarityWithDefaultOverride, TestFieldCollectionResource, ZkStateReaderTest]
[junit4] Completed [12/571 (1!)] on J1 in 5.54s, 6 tests, 1 error <<< FAILURES!
[...truncated 1787 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/build.xml:750: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/build.xml:694: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build.xml:233: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/common-build.xml:534: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/lucene/common-build.xml:1477: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/lucene/common-build.xml:1033: There were test failures: 571 suites (7 ignored), 2289 tests, 1 error, 55 ignored (39 assumptions) [seed: 94FE21DB598E0A3B]
Total time: 87 minutes 58 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any
[JENKINS] Lucene-Solr-Tests-5.5-Java8 - Build # 3 - Still Failing
Posted by Apache Jenkins Server <je...@builds.apache.org>.
Build: https://builds.apache.org/job/Lucene-Solr-Tests-5.5-Java8/3/
3 tests failed.
FAILED: org.apache.solr.update.AutoCommitTest.testMaxTime
Error Message:
Exception during query
Stack Trace:
java.lang.RuntimeException: Exception during query
at __randomizedtesting.SeedInfo.seed([1CE1D579B8F796DC:8615A89B266D0AE0]:0)
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:754)
at org.apache.solr.update.AutoCommitTest.testMaxTime(AutoCommitTest.java:243)
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:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
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:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound=1]
xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader"><int name="status">0</int><int name="QTime">0</int></lst><result name="response" numFound="0" start="0"></result>
</response>
request was:q=id:529&qt=standard&start=0&rows=20&version=2.2
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:747)
... 40 more
FAILED: org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete
Error Message:
Got a soft commit we weren't expecting
Stack Trace:
java.lang.AssertionError: Got a soft commit we weren't expecting
at __randomizedtesting.SeedInfo.seed([1CE1D579B8F796DC:DBAD6DE4A35F5B6C]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNull(Assert.java:551)
at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete(SoftAutoCommitTest.java:287)
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:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
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:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at java.lang.Thread.run(Thread.java:745)
FAILED: org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh
Error Message:
Could not find collection : c1
Stack Trace:
org.apache.solr.common.SolrException: Could not find collection : c1
at __randomizedtesting.SeedInfo.seed([1CE1D579B8F796DC:35BA48E68975019]:0)
at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:170)
at org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdate(ZkStateReaderTest.java:136)
at org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh(ZkStateReaderTest.java:42)
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:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
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:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 10906 lines...]
[junit4] Suite: org.apache.solr.update.SoftAutoCommitTest
[junit4] 2> Creating dataDir: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001
[junit4] 2> 582072 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (true)
[junit4] 2> 582072 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore
[junit4] 2> 582072 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
[junit4] 2> 582073 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 582073 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
[junit4] 2> 582073 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 582073 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 582144 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 582158 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.5.0
[junit4] 2> 582188 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 582192 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.s.IndexSchema [null] Schema name=test
[junit4] 2> 582259 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 582262 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 582263 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 582271 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 582272 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 582309 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 582309 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 582310 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 582310 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
[junit4] 2> 582310 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr'
[junit4] 2> 582310 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 582310 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
[junit4] 2> 582310 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.CoreContainer New CoreContainer 1385203522
[junit4] 2> 582310 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.CoreContainer Loading cores into CoreContainer [instanceDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr]
[junit4] 2> 582310 WARN (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.CoreContainer Couldn't add files from /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/lib to classpath: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/lib
[junit4] 2> 582322 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.h.c.HttpShardHandlerFactory created with socketTimeout : 600000,connTimeout : 60000,maxConnectionsPerHost : 20,maxConnections : 10000,corePoolSize : 0,maximumPoolSize : 2147483647,maxThreadIdleTime : 5,sizeOfQueue : -1,fairnessPolicy : false,useRetries : false,
[junit4] 2> 582328 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=30000&connTimeout=30000&retry=true
[junit4] 2> 582328 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.l.LogWatcher SLF4J impl is org.slf4j.impl.Log4jLoggerFactory
[junit4] 2> 582329 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.l.LogWatcher Registering Log Listener [Log4j (org.slf4j.impl.Log4jLoggerFactory)]
[junit4] 2> 582329 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.CoreContainer Security conf doesn't exist. Skipping setup for authorization module.
[junit4] 2> 582329 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.CoreContainer No authentication plugin used.
[junit4] 2> 582329 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.c.CoreDescriptor Created CoreDescriptor: {name=collection1, config=solrconfig.xml, transient=false, schema=schema.xml, loadOnStartup=true, configSetProperties=configsetprops.json, collection=collection1, dataDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001, shard=shard1}
[junit4] 2> 582329 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
[junit4] 2> 582346 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 582346 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
[junit4] 2> 582346 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 582346 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 582364 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 582373 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.5.0
[junit4] 2> 582482 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 582491 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 582641 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 582664 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 582665 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 582676 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 582677 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 582684 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 582684 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 582685 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
[junit4] 2> 582685 INFO (coreLoadExecutor-1005-thread-1) [ ] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1
[junit4] 2> 582686 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.SolrCore org.apache.solr.core.MockDirectoryFactory
[junit4] 2> 582686 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/]
[junit4] 2> 582686 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5b7d090b
[junit4] 2> 582686 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001
[junit4] 2> 582686 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/index/
[junit4] 2> 582686 WARN (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.SolrCore [collection1] Solr index directory '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/index' doesn't exist. Creating new index...
[junit4] 2> 582686 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.CachingDirectoryFactory return new directory for /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/index
[junit4] 2> 582687 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: minMergeSize=1677721, mergeFactor=32, maxMergeSize=2147483648, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.0]
[junit4] 2> 582687 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_1,generation=1}
[junit4] 2> 582687 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 582689 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
[junit4] 2> 582689 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 582689 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 582689 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 582689 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 582690 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 582690 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 582690 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 582690 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 582690 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 582690 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 582690 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 582691 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 582692 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 582692 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 582693 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 582695 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.PluginBag requestHandler : 'lazy' created with startup=lazy
[junit4] 2> 582696 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
[junit4] 2> 582696 WARN (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.SolrCore solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 582696 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 582697 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [ x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/
[junit4] 2> 582697 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 582697 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 582698 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 582698 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 582698 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=37, maxMergeAtOnceExplicit=18, maxMergedSegmentMB=4.1064453125, floorSegmentMB=1.7529296875, forceMergeDeletesPctAllowed=23.425354893011864, segmentsPerTier=29.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.8872145663403272
[junit4] 2> 582698 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_1,generation=1}
[junit4] 2> 582698 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 582699 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@3603b37[collection1] main
[junit4] 2> 582699 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 582699 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 582699 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 582699 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 582706 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 582736 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 582737 INFO (searcherExecutor-1006-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 582737 INFO (searcherExecutor-1006-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 582737 INFO (searcherExecutor-1006-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 582737 INFO (searcherExecutor-1006-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 582737 INFO (searcherExecutor-1006-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 582737 INFO (searcherExecutor-1006-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 582737 INFO (searcherExecutor-1006-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 582738 INFO (searcherExecutor-1006-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 582738 INFO (searcherExecutor-1006-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 582738 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
[junit4] 2> 582738 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version buckets from index
[junit4] 2> 582738 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket highest value from index
[junit4] 2> 582738 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1532356284686270464
[junit4] 2> 582740 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.u.UpdateLog Took 1.0ms to seed version buckets with highest version 1532356284686270464
[junit4] 2> 582740 INFO (coreLoadExecutor-1005-thread-1) [ x:collection1] o.a.s.c.CoreContainer registering core: collection1
[junit4] 2> 582741 INFO (searcherExecutor-1006-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3603b37[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 582741 INFO (SUITE-SoftAutoCommitTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.SolrTestCaseJ4 ####initCore end
[junit4] 2> 582743 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 582743 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
[junit4] 2> 582743 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 582743 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
[junit4] 2> 582743 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 582743 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 582798 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 582812 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.5.0
[junit4] 2> 582846 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 582849 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 583095 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 583107 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 583107 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 583110 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 583111 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 583112 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 583112 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 583114 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
[junit4] 2> 583114 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1
[junit4] 2> 583130 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/]
[junit4] 2> 583130 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5b7d090b
[junit4] 2> 583131 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/index/
[junit4] 2> 583133 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [ x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/
[junit4] 2> 583166 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
[junit4] 2> 583166 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 583166 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 583166 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 583166 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 583166 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 583167 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 583167 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 583167 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 583167 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 583167 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 583167 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 583189 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 583190 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 583191 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 583196 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 583205 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.PluginBag requestHandler : 'lazy' created with startup=lazy
[junit4] 2> 583206 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
[junit4] 2> 583207 WARN (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 583207 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 583216 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 583216 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 583223 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@68262080[collection1] main
[junit4] 2> 583223 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 583224 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 583224 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 583224 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 583224 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 583226 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 583227 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
[junit4] 2> 583227 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version buckets from index
[junit4] 2> 583227 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.VersionInfo No terms found for _version_, cannot seed version bucket highest value from index
[junit4] 2> 583227 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1532356285199024128
[junit4] 2> 583229 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.UpdateLog Took 1.0ms to seed version buckets with highest version 1532356285199024128
[junit4] 2> 583229 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.DefaultSolrCoreState Closing old IndexWriter... core=collection1
[junit4] 2> 583242 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 583242 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 583242 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 583243 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 583243 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 583243 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 583243 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 583243 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 583243 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 583244 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@68262080[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 583250 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: minMergeSize=1000, mergeFactor=14, maxMergeSize=9223372036854775807, maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0]
[junit4] 2> 583251 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_1,generation=1}
[junit4] 2> 583251 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 1
[junit4] 2> 583251 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 583251 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@4bcebcc3[collection1] main
[junit4] 2> 583251 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.CoreContainer replacing core: collection1
[junit4] 2> 583251 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@6ebec18e
[junit4] 2> 583251 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.DirectUpdateHandler2 closing DirectUpdateHandler2{commits=0,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=0,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=0,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
[junit4] 2> 583252 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore [collection1] Closing main searcher on request.
[junit4] 2> 583253 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@4bcebcc3[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 583265 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5000 (1532356285236772864)]} 0 1
[junit4] 2> 583266 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5001 (1532356285239918592)]} 0 0
[junit4] 2> 583267 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5002 (1532356285240967168)]} 0 0
[junit4] 2> 583268 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5003 (1532356285242015744)]} 0 0
[junit4] 2> 583268 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[5004 (1532356285242015745)]} 0 0
[junit4] 2> 583269 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeRapidAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeRapidAdds
[junit4] 2> 583272 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeDelete
[junit4] 2> 583272 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
[junit4] 2> 583272 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 583272 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
[junit4] 2> 583272 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 583273 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 583315 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 583327 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.5.0
[junit4] 2> 583360 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 583369 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 583731 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 583778 INFO (commitScheduler-1014-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 583812 INFO (commitScheduler-1014-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@b44d014[collection1] main
[junit4] 2> 583813 INFO (searcherExecutor-1011-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@b44d014[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5)))}
[junit4] 2> 583813 INFO (commitScheduler-1014-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 583815 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 583816 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 583818 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 583827 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 583828 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 583828 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 583829 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
[junit4] 2> 583829 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1
[junit4] 2> 583838 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/]
[junit4] 2> 583838 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5b7d090b
[junit4] 2> 583838 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore New index directory detected: old=null new=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/index/
[junit4] 2> 583844 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe"
[junit4] 2> 583845 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4] 2> 583845 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 583845 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe-allfields"
[junit4] 2> 583845 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "stored_sig"
[junit4] 2> 583845 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4] 2> 583845 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "uniq-fields"
[junit4] 2> 583845 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "uniq-fields"
[junit4] 2> 583845 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-explicit"
[junit4] 2> 583845 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain creating updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 583845 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.UpdateRequestProcessorChain inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4] 2> 583845 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore no updateRequestProcessorChain defined as default, creating implicit default
[junit4] 2> 583846 INFO (OldIndexDirectoryCleanupThreadForCore-collection1) [ x:collection1] o.a.s.c.SolrCore Looking for old index directories to cleanup for core collection1 in /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/
[junit4] 2> 583853 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 583854 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 583854 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 583855 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.h.l.XMLLoader xsltCacheLifetimeSeconds=60
[junit4] 2> 583869 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.PluginBag requestHandler : 'lazy' created with startup=lazy
[junit4] 2> 583870 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.RequestHandlers Registered paths: /admin/mbeans,standard,spellCheckCompRH,lazy,/update/json/docs,/admin/luke,spellCheckWithWordbreak_Direct,tvrh,/get,/admin/properties,/update/json,mltrh,/admin/threads,/search-facet-def,/update/csv,/search-facet-invariants,/admin/segments,spellCheckCompRH1,/mlt,/admin/system,/replication,dismax,defaults,/config,/schema,/admin/plugins,/admin/logging,spellCheckWithWordbreak,mock,/admin/ping,/update,/admin/file,/terms,spellCheckCompRH_Direct,/debug/dump
[junit4] 2> 583870 WARN (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore solrconfig.xml uses deprecated <admin/gettableFiles>, Please update your config to use the ShowFileRequestHandler.
[junit4] 2> 583871 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore Using default statsCache cache: org.apache.solr.search.stats.LocalStatsCache
[junit4] 2> 583875 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 583875 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 583883 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@3dcff18d[collection1] main
[junit4] 2> 583883 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.r.RestManager Initializing RestManager with initArgs: {storageIO=org.apache.solr.rest.ManagedResourceStorage$InMemoryStorageIO}
[junit4] 2> 583883 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.r.ManagedResourceStorage Reading _rest_managed.json using InMemoryStorage
[junit4] 2> 583883 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.r.RestManager Initializing 0 registered ManagedResources
[junit4] 2> 583883 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
[junit4] 2> 583884 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.DirectSolrSpellChecker init: {name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
[junit4] 2> 583887 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 583889 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.UpdateLog Looking up max value of version field to seed version buckets
[junit4] 2> 583889 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.VersionInfo Refreshing highest value of _version_ for 65536 version buckets from index
[junit4] 2> 583891 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.VersionInfo Found MAX value 1532356285242015745 from Terms for _version_ in index
[junit4] 2> 583893 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.UpdateLog Took 3.0ms to seed version buckets with highest version 1532356285242015745
[junit4] 2> 583893 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.DefaultSolrCoreState Closing old IndexWriter... core=collection1
[junit4] 2> 583893 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
[junit4] 2> 583893 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
[junit4] 2> 583893 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
[junit4] 2> 583893 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: multipleFields
[junit4] 2> 583893 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
[junit4] 2> 583894 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
[junit4] 2> 583894 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
[junit4] 2> 583894 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
[junit4] 2> 583894 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
[junit4] 2> 583895 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@3dcff18d[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5)))}
[junit4] 2> 583903 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_1,generation=1}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_2,generation=2}
[junit4] 2> 583903 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 2
[junit4] 2> 583904 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: maxMergeAtOnce=34, maxMergeAtOnceExplicit=13, maxMergedSegmentMB=80.1572265625, floorSegmentMB=1.9609375, forceMergeDeletesPctAllowed=23.35010565591937, segmentsPerTier=22.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
[junit4] 2> 583918 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_2,generation=2}
[junit4] 2> 583918 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 2
[junit4] 2> 583934 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 583939 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@368ace18[collection1] main
[junit4] 2> 583939 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.CoreContainer replacing core: collection1
[junit4] 2> 583939 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@1f09fa16
[junit4] 2> 583939 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.DirectUpdateHandler2 closing DirectUpdateHandler2{commits=1,autocommit maxTime=1200ms,autocommits=0,soft autocommit maxTime=500ms,soft autocommits=1,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=5,adds=0,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=5,cumulative_deletesById=0,cumulative_deletesByQuery=0,cumulative_errors=0,transaction_logs_total_size=0,transaction_logs_total_number=0}
[junit4] 2> 583940 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@368ace18[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5)))}
[junit4] 2> 583940 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore [collection1] Closing main searcher on request.
[junit4] 2> 583986 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[529 (1532356285970776064)]} 0 23
[junit4] 2> 583987 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 583998 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_2,generation=2}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_3,generation=3}
[junit4] 2> 583998 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 3
[junit4] 2> 583998 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@2ea2e9ff[collection1] main
[junit4] 2> 583999 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 584032 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@2ea2e9ff[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5) Uninverting(_1(5.5.0):C1)))}
[junit4] 2> 584034 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{commit=} 0 47
[junit4] 2> 584035 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{delete=[529 (-1532356286045224960)]} 0 0
[junit4] 2> 584673 INFO (commitScheduler-1018-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 584677 INFO (commitScheduler-1018-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@1e53f597[collection1] main
[junit4] 2> 584678 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@1e53f597[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5)))}
[junit4] 2> 584678 INFO (commitScheduler-1018-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 584684 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.u.p.LogUpdateProcessorFactory [collection1] webapp=null path=null params={}{add=[550 (1532356286720507904)]} 0 5
[junit4] 2> 585323 INFO (commitScheduler-1018-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=true,prepareCommit=false}
[junit4] 2> 585324 INFO (commitScheduler-1017-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 585327 INFO (commitScheduler-1018-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@604541c6[collection1] main
[junit4] 2> 585329 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@604541c6[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5) Uninverting(_2(5.5.0):C1)))}
[junit4] 2> 585330 INFO (commitScheduler-1017-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onCommit: commits: num=2
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_3,generation=3}
[junit4] 2> commit{dir=MockDirectoryWrapper(RAMDirectory@7bd7ca07 lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@546b13d6),segFN=segments_4,generation=4}
[junit4] 2> 585330 INFO (commitScheduler-1017-thread-1) [ x:collection1] o.a.s.c.SolrDeletionPolicy newest commit generation = 4
[junit4] 2> 585330 INFO (commitScheduler-1017-thread-1) [ x:collection1] o.a.s.s.SolrIndexSearcher Opening Searcher@42515eef[collection1] main
[junit4] 2> 585331 INFO (searcherExecutor-1015-thread-1-processing-x:collection1) [ x:collection1] o.a.s.c.SolrCore [collection1] Registered new searcher Searcher@42515eef[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(5.5.0):C5) Uninverting(_2(5.5.0):C1)))}
[junit4] 2> 585331 INFO (commitScheduler-1017-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 585331 INFO (commitScheduler-1018-thread-1) [ x:collection1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 587331 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Ending testSoftAndHardCommitMaxTimeDelete
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=SoftAutoCommitTest -Dtests.method=testSoftAndHardCommitMaxTimeDelete -Dtests.seed=1CE1D579B8F796DC -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=en -Dtests.timezone=Pacific/Honolulu -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] FAILURE 4.07s J1 | SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete <<<
[junit4] > Throwable #1: java.lang.AssertionError: Got a soft commit we weren't expecting
[junit4] > at __randomizedtesting.SeedInfo.seed([1CE1D579B8F796DC:DBAD6DE4A35F5B6C]:0)
[junit4] > at org.apache.solr.update.SoftAutoCommitTest.testSoftAndHardCommitMaxTimeDelete(SoftAutoCommitTest.java:287)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 587347 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.SolrTestCaseJ4 ###Starting testSoftAndHardCommitMaxTimeMixedAdds
[junit4] 2> 587347 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrResourceLoader new SolrResourceLoader for directory: '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
[junit4] 2> 587347 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrResourceLoader JNDI not configured for solr (NoInitialContextEx)
[junit4] 2> 587347 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrResourceLoader using system property solr.solr.home: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr
[junit4] 2> 587348 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/classes/' to classloader
[junit4] 2> 587348 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrResourceLoader Adding 'file:/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1/lib/README' to classloader
[junit4] 2> 587385 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrConfig current version of requestparams : -1
[junit4] 2> 587390 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 5.5.0
[junit4] 2> 587403 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrConfig Loaded SolrConfig: solrconfig.xml
[junit4] 2> 587407 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
[junit4] 2> 587563 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Initialized with rates=open-exchange-rates.json, refreshInterval=1440.
[junit4] 2> 587577 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.IndexSchema default search field in schema is text
[junit4] 2> 587578 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.IndexSchema unique key field: id
[junit4] 2> 587580 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 587582 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.FileExchangeRateProvider Reloading exchange rates from file currency.xml
[junit4] 2> 587591 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 587591 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.s.OpenExchangeRatesOrgProvider Reloading exchange rates from open-exchange-rates.json
[junit4] 2> 587592 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.ConfigSetProperties Did not find ConfigSet properties, assuming default properties: Can't find resource 'configsetprops.json' in classpath or '/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1'
[junit4] 2> 587592 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.CoreContainer Reloading SolrCore 'collection1' using configuration from instancedir /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1
[junit4] 2> 587593 INFO (TEST-SoftAutoCommitTest.testSoftAndHardCommitMaxTimeMixedAdds-seed#[1CE1D579B8F796DC]) [ x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at [/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/core/src/test-files/solr/collection1], dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.update.SoftAutoCommitTest_1CE1D579B8F796DC-001/init-core-data-001/]
[j
[...truncated too long message...]
state from ZooKeeper...
[junit4] 2> 2458633 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.c.ZkStateReader addZkWatch [c1]
[junit4] 2> 2458633 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.c.ZkStateReader Deleting data for [c1]
[junit4] 2> 2458633 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.c.SolrZkClient makePath: /collections/c1
[junit4] 2> 2458635 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.o.ZkStateWriter going to create_collection /collections/c1/state.json
[junit4] 2> 2458636 INFO (zkCallback-2205-thread-1) [ ] o.a.s.c.c.ZkStateReader A collections change: [WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/collections], has occurred - updating...
[junit4] 2> 2458636 INFO (zkCallback-2205-thread-2) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json], has occurred - updating... (live nodes size: [0])
[junit4] 2> 2458636 INFO (zkCallback-2205-thread-3) [ ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeCreated path:/collections/c1/state.json] for collection [c1] has occurred - updating... (live nodes size: [0])
[junit4] 2> 2460275 WARN (zkCallback-2205-thread-1) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /collections]
[junit4] 2> 2460275 WARN (zkCallback-2205-thread-3) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /collections/c1/state.json]
[junit4] 2> 2460275 WARN (zkCallback-2205-thread-2) [ ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /clusterstate.json]
[junit4] 2> 2460287 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[1CE1D579B8F796DC]) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37517 37517
[junit4] 2> 2460419 INFO (Thread-5640) [ ] o.a.s.c.ZkTestServer connecting to 127.0.0.1:37517 37517
[junit4] 2> 2460420 INFO (TEST-ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh-seed#[1CE1D579B8F796DC]) [ ] o.a.s.SolrTestCaseJ4 ###Ending testStateFormatUpdateWithExplicitRefresh
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=ZkStateReaderTest -Dtests.method=testStateFormatUpdateWithExplicitRefresh -Dtests.seed=1CE1D579B8F796DC -Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=pt-PT -Dtests.timezone=America/Cancun -Dtests.asserts=true -Dtests.file.encoding=ISO-8859-1
[junit4] ERROR 2.09s J1 | ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh <<<
[junit4] > Throwable #1: org.apache.solr.common.SolrException: Could not find collection : c1
[junit4] > at __randomizedtesting.SeedInfo.seed([1CE1D579B8F796DC:35BA48E68975019]:0)
[junit4] > at org.apache.solr.common.cloud.ClusterState.getCollection(ClusterState.java:170)
[junit4] > at org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdate(ZkStateReaderTest.java:136)
[junit4] > at org.apache.solr.cloud.overseer.ZkStateReaderTest.testStateFormatUpdateWithExplicitRefresh(ZkStateReaderTest.java:42)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2460421 INFO (SUITE-ZkStateReaderTest-seed#[1CE1D579B8F796DC]-worker) [ ] o.a.s.SolrTestCaseJ4 ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: /x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build/solr-core/test/J1/temp/solr.cloud.overseer.ZkStateReaderTest_1CE1D579B8F796DC-001
[junit4] 2> Apr 23, 2016 12:18:29 AM com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
[junit4] 2> WARNING: Will linger awaiting termination of 1 leaked thread(s).
[junit4] 2> NOTE: test params are: codec=Asserting(Lucene54): {}, docValues:{}, sim=DefaultSimilarity, locale=pt-PT, timezone=America/Cancun
[junit4] 2> NOTE: Linux 3.13.0-52-generic amd64/Oracle Corporation 1.8.0_74 (64-bit)/cpus=4,threads=1,free=230324144,total=522190848
[junit4] 2> NOTE: All tests run in this JVM: [TestPerFieldSimilarityWithDefaultOverride, TestCursorMarkWithoutUniqueKey, OverseerRolesTest, TestSearcherReuse, TestDocumentBuilder, SaslZkACLProviderTest, TestHashPartitioner, LeaderInitiatedRecoveryOnShardRestartTest, TestSolrDeletionPolicy2, TestConfigOverlay, TestLFUCache, SpatialFilterTest, UpdateRequestProcessorFactoryTest, SimplePostToolTest, TestJsonRequest, SpellPossibilityIteratorTest, SortByFunctionTest, SpellCheckCollatorTest, AliasIntegrationTest, SpellCheckComponentTest, TestSolrConfigHandlerConcurrent, HighlighterTest, ConvertedLegacyTest, CollectionsAPIDistributedZkTest, DistanceFunctionTest, TestPartialUpdateDeduplication, DistribCursorPagingTest, TestMiniSolrCloudClusterSSL, BlockJoinFacetSimpleTest, TestSerializedLuceneMatchVersion, CursorMarkTest, SoftAutoCommitTest, RecoveryAfterSoftCommitTest, TestAnalyzeInfixSuggestions, TestManagedSchemaAPI, CloudExitableDirectoryReaderTest, RulesTest, MoreLikeThisHandlerTest, TestReqParamsAPI, TestStressVersions, TestDistribIDF, TestCloudInspectUtil, TestAuthorizationFramework, DocumentBuilderTest, TestUseDocValuesAsStored2, ExitableDirectoryReaderTest, HdfsWriteToMultipleCollectionsTest, DistributedTermsComponentTest, TestFreeTextSuggestions, OpenExchangeRatesOrgProviderTest, MinimalSchemaTest, TestFastLRUCache, ShardRoutingTest, TestSolr4Spatial2, TestExclusionRuleCollectionAccess, DistributedMLTComponentTest, CollectionTooManyReplicasTest, TestTrie, BitVectorTest, TestUniqueKeyFieldResource, UniqFieldsUpdateProcessorFactoryTest, HdfsLockFactoryTest, TestTrieFacet, TestMiniSolrCloudCluster, TestTestInjection, TestDFRSimilarityFactory, DistributedFacetPivotLargeTest, SpatialHeatmapFacetsTest, TestBulkSchemaAPI, SolrCmdDistributorTest, TestDistributedStatsComponentCardinality, TestRequestStatusCollectionAPI, BasicFunctionalityTest, FastVectorHighlighterTest, TestLRUStatsCache, TestEmbeddedSolrServerConstructors, TestQuerySenderListener, MultiTermTest, TestBlobHandler, TestDistributedGrouping, BJQParserTest, DataDrivenBlockJoinTest, TestMaxScoreQueryParser, TestInfoStreamLogging, TestCryptoKeys, TimeZoneUtilsTest, OpenCloseCoreStressTest, TestMinMaxOnMultiValuedField, OutOfBoxZkACLAndCredentialsProvidersTest, MBeansHandlerTest, TestTrackingShardHandlerFactory, DistributedSpellCheckComponentTest, ZkControllerTest, TestReload, HardAutoCommitTest, BadIndexSchemaTest, TestFiltering, SolrIndexSplitterTest, SuggesterFSTTest, DocValuesTest, SuggesterTSTTest, TestStressLucene, NoCacheHeaderTest, SchemaVersionSpecificBehaviorTest, FieldMutatingUpdateProcessorTest, QueryEqualityTest, TestRemoteStreaming, DocValuesMultiTest, TestSolrDeletionPolicy1, DebugComponentTest, IndexBasedSpellCheckerTest, LukeRequestHandlerTest, TestQueryTypes, RequestHandlersTest, TermVectorComponentTest, RequiredFieldsTest, IndexSchemaRuntimeFieldTest, SolrPluginUtilsTest, TestCollationField, TestCSVResponseWriter, TestAnalyzedSuggestions, BinaryUpdateRequestHandlerTest, CSVRequestHandlerTest, TestComponentsName, TestBinaryResponseWriter, UpdateParamsTest, AlternateDirectoryTest, TestQuerySenderNoQuery, ResponseLogComponentTest, SolrIndexConfigTest, TestDocSet, TestBinaryField, NumericFieldsTest, TestConfig, OutputWriterTest, TestSolrCoreProperties, DirectSolrConnectionTest, NotRequiredUniqueKeyTest, TestPhraseSuggestions, TestCodecSupport, TestXIncludeConfig, EchoParamsTest, TestLMJelinekMercerSimilarityFactory, TestFastWriter, PluginInfoTest, ChaosMonkeyNothingIsSafeTest, TestCrossCoreJoin, TestSimpleTrackingShardHandler, TestTolerantSearch, ConnectionReuseTest, CleanupOldIndexTest, ConfigSetsAPITest, DeleteInactiveReplicaTest, DeleteReplicaTest, DistributedQueueTest, DistributedVersionInfoTest, LeaderFailoverAfterPartitionTest, MigrateRouteKeyTest, TestCollectionAPI, TestLeaderInitiatedRecoveryThread, TestRequestForwarding, TestSolrCloudWithKerberosAlt, VMParamsZkACLAndCredentialsProvidersTest, HdfsBasicDistributedZk2Test, HdfsBasicDistributedZkTest, HdfsChaosMonkeySafeLeaderTest, HdfsRecoverLeaseTest, TestClusterStateMutator, ZkStateReaderTest]
[junit4] Completed [462/571 (3!)] on J1 in 6.42s, 6 tests, 1 error <<< FAILURES!
[...truncated 356 lines...]
BUILD FAILED
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/build.xml:750: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/build.xml:694: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/build.xml:59: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/build.xml:233: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/solr/common-build.xml:534: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/lucene/common-build.xml:1477: The following error occurred while executing this line:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-5.5-Java8/lucene/common-build.xml:1033: There were test failures: 571 suites (7 ignored), 2289 tests, 2 errors, 1 failure, 55 ignored (39 assumptions) [seed: 1CE1D579B8F796DC]
Total time: 88 minutes 11 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
No prior successful build to compare, so performing full copy of artifacts
Recording test results
Email was triggered for: Failure - Any
Sending email for trigger: Failure - Any