You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Apache Jenkins Server <je...@builds.apache.org> on 2013/05/30 23:04:33 UTC
[JENKINS] Lucene-Solr-Tests-4.x-Java6 - Build # 1668 - Failure
Build: https://builds.apache.org/job/Lucene-Solr-Tests-4.x-Java6/1668/
1 tests failed.
REGRESSION: org.apache.solr.cloud.ShardSplitTest.testDistribSearch
Error Message:
Server at http://127.0.0.1:58798/ao_dxt/c returned non ok status:500, message:Server Error
Stack Trace:
org.apache.solr.client.solrj.impl.HttpSolrServer$RemoteSolrException: Server at http://127.0.0.1:58798/ao_dxt/c returned non ok status:500, message:Server Error
at __randomizedtesting.SeedInfo.seed([3A01D2A146E95E0E:BBE75CB931B63E32]:0)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:385)
at org.apache.solr.client.solrj.impl.HttpSolrServer.request(HttpSolrServer.java:180)
at org.apache.solr.cloud.ShardSplitTest.splitShard(ShardSplitTest.java:208)
at org.apache.solr.cloud.ShardSplitTest.doTest(ShardSplitTest.java:133)
at org.apache.solr.BaseDistributedSearchTestCase.testDistribSearch(BaseDistributedSearchTestCase.java:815)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:616)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1559)
at com.carrotsearch.randomizedtesting.RandomizedRunner.access$600(RandomizedRunner.java:79)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:737)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:773)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:787)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:50)
at org.apache.lucene.util.TestRuleFieldCacheSanity$1.evaluate(TestRuleFieldCacheSanity.java:51)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:49)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:782)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:442)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:746)
at com.carrotsearch.randomizedtesting.RandomizedRunner$3.evaluate(RandomizedRunner.java:648)
at com.carrotsearch.randomizedtesting.RandomizedRunner$4.evaluate(RandomizedRunner.java:682)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:693)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:53)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:46)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:42)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesInvariantRule$1.evaluate(SystemPropertiesInvariantRule.java:55)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:39)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:43)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:70)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:55)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:358)
at java.lang.Thread.run(Thread.java:679)
Build Log:
[...truncated 9597 lines...]
[junit4:junit4] Suite: org.apache.solr.cloud.ShardSplitTest
[junit4:junit4] 2> 1555735 T4607 oas.BaseDistributedSearchTestCase.initHostContext Setting hostContext system property: /ao_dxt/c
[junit4:junit4] 2> 1555741 T4607 oas.SolrTestCaseJ4.setUp ###Starting testDistribSearch
[junit4:junit4] 2> Creating dataDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./solrtest-ShardSplitTest-1369947787049
[junit4:junit4] 2> 1555742 T4607 oasc.ZkTestServer.run STARTING ZK TEST SERVER
[junit4:junit4] 2> 1555743 T4608 oasc.ZkTestServer$ZKServerMain.runFromConfig Starting server
[junit4:junit4] 2> 1555844 T4607 oasc.ZkTestServer.run start zk server on port:29787
[junit4:junit4] 2> 1555845 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1555850 T4614 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@189941d3 name:ZooKeeperConnection Watcher:127.0.0.1:29787 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1555850 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1555850 T4607 oascc.SolrZkClient.makePath makePath: /solr
[junit4:junit4] 2> 1555870 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1555872 T4616 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@1688a2d1 name:ZooKeeperConnection Watcher:127.0.0.1:29787/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1555872 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1555873 T4607 oascc.SolrZkClient.makePath makePath: /collections/collection1
[junit4:junit4] 2> 1555882 T4607 oascc.SolrZkClient.makePath makePath: /collections/collection1/shards
[junit4:junit4] 2> 1555885 T4607 oascc.SolrZkClient.makePath makePath: /collections/control_collection
[junit4:junit4] 2> 1555888 T4607 oascc.SolrZkClient.makePath makePath: /collections/control_collection/shards
[junit4:junit4] 2> 1555895 T4607 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/solrconfig-tlog.xml to /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 1555896 T4607 oascc.SolrZkClient.makePath makePath: /configs/conf1/solrconfig.xml
[junit4:junit4] 2> 1555909 T4607 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/schema15.xml to /configs/conf1/schema.xml
[junit4:junit4] 2> 1555910 T4607 oascc.SolrZkClient.makePath makePath: /configs/conf1/schema.xml
[junit4:junit4] 2> 1556015 T4607 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/stopwords.txt to /configs/conf1/stopwords.txt
[junit4:junit4] 2> 1556016 T4607 oascc.SolrZkClient.makePath makePath: /configs/conf1/stopwords.txt
[junit4:junit4] 2> 1556019 T4607 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/protwords.txt to /configs/conf1/protwords.txt
[junit4:junit4] 2> 1556020 T4607 oascc.SolrZkClient.makePath makePath: /configs/conf1/protwords.txt
[junit4:junit4] 2> 1556023 T4607 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/currency.xml to /configs/conf1/currency.xml
[junit4:junit4] 2> 1556024 T4607 oascc.SolrZkClient.makePath makePath: /configs/conf1/currency.xml
[junit4:junit4] 2> 1556027 T4607 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/open-exchange-rates.json to /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 1556028 T4607 oascc.SolrZkClient.makePath makePath: /configs/conf1/open-exchange-rates.json
[junit4:junit4] 2> 1556035 T4607 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/mapping-ISOLatin1Accent.txt to /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 1556036 T4607 oascc.SolrZkClient.makePath makePath: /configs/conf1/mapping-ISOLatin1Accent.txt
[junit4:junit4] 2> 1556039 T4607 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/old_synonyms.txt to /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 1556040 T4607 oascc.SolrZkClient.makePath makePath: /configs/conf1/old_synonyms.txt
[junit4:junit4] 2> 1556043 T4607 oasc.AbstractZkTestCase.putConfig put /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test-files/solr/collection1/conf/synonyms.txt to /configs/conf1/synonyms.txt
[junit4:junit4] 2> 1556044 T4607 oascc.SolrZkClient.makePath makePath: /configs/conf1/synonyms.txt
[junit4:junit4] 2> 1556302 T4607 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1556307 T4607 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:55609
[junit4:junit4] 2> 1556308 T4607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1556309 T4607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1556309 T4607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1369947787361
[junit4:junit4] 2> 1556310 T4607 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1369947787361/solr.xml
[junit4:junit4] 2> 1556310 T4607 oasc.CoreContainer.<init> New CoreContainer 1641972137
[junit4:junit4] 2> 1556311 T4607 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1369947787361/'
[junit4:junit4] 2> 1556311 T4607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1369947787361/'
[junit4:junit4] 2> 1556423 T4607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1556424 T4607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1556424 T4607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1556425 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1556425 T4607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1556426 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1556426 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1556427 T4607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1556427 T4607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1556428 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1556444 T4607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1556445 T4607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:29787/solr
[junit4:junit4] 2> 1556445 T4607 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1556446 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1556449 T4627 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@bfdf760 name:ZooKeeperConnection Watcher:127.0.0.1:29787 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1556449 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1556452 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1556462 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1556464 T4629 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5c27c8e5 name:ZooKeeperConnection Watcher:127.0.0.1:29787/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1556464 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1556466 T4607 oascc.SolrZkClient.makePath makePath: /overseer/queue
[junit4:junit4] 2> 1556475 T4607 oascc.SolrZkClient.makePath makePath: /overseer/collection-queue-work
[junit4:junit4] 2> 1556479 T4607 oascc.SolrZkClient.makePath makePath: /live_nodes
[junit4:junit4] 2> 1556486 T4607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:55609_ao_dxt%2Fc
[junit4:junit4] 2> 1556487 T4607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:55609_ao_dxt%2Fc
[junit4:junit4] 2> 1556491 T4607 oascc.SolrZkClient.makePath makePath: /overseer_elect/election
[junit4:junit4] 2> 1556507 T4607 oascc.SolrZkClient.makePath makePath: /overseer_elect/leader
[junit4:junit4] 2> 1556510 T4607 oasc.Overseer.start Overseer (id=89780898172502019-127.0.0.1:55609_ao_dxt%2Fc-n_0000000000) starting
[junit4:junit4] 2> 1556521 T4607 oascc.SolrZkClient.makePath makePath: /overseer/queue-work
[junit4:junit4] 2> 1556530 T4631 oasc.OverseerCollectionProcessor.run Process current queue of collection creations
[junit4:junit4] 2> 1556530 T4607 oascc.SolrZkClient.makePath makePath: /clusterstate.json
[junit4:junit4] 2> 1556538 T4607 oascc.SolrZkClient.makePath makePath: /aliases.json
[junit4:junit4] 2> 1556540 T4607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1556542 T4630 oasc.Overseer$ClusterStateUpdater.run Starting to work on the main queue
[junit4:junit4] 2> 1556546 T4632 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1369947787361/collection1
[junit4:junit4] 2> 1556546 T4632 oasc.ZkController.createCollectionZkNode Check for collection zkNode:control_collection
[junit4:junit4] 2> 1556547 T4632 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1556547 T4632 oasc.ZkController.readConfigName Load collection config from:/collections/control_collection
[junit4:junit4] 2> 1556549 T4632 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1369947787361/collection1/'
[junit4:junit4] 2> 1556550 T4632 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1369947787361/collection1/lib/README' to classloader
[junit4:junit4] 2> 1556551 T4632 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-controljetty-1369947787361/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1556602 T4632 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1556659 T4632 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1556761 T4632 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1556769 T4632 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1557304 T4632 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1557307 T4632 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1557308 T4632 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1557312 T4632 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1557333 T4632 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1557333 T4632 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-controljetty-1369947787361/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1369947787048/control/data/
[junit4:junit4] 2> 1557333 T4632 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c2bfdff
[junit4:junit4] 2> 1557334 T4632 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1557334 T4632 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1369947787048/control/data
[junit4:junit4] 2> 1557334 T4632 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1369947787048/control/data/index/
[junit4:junit4] 2> 1557335 T4632 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1369947787048/control/data/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1557335 T4632 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1369947787048/control/data/index
[junit4:junit4] 2> 1557338 T4632 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fe7089a lockFactory=org.apache.lucene.store.NativeFSLockFactory@26b7dac5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1557338 T4632 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1557341 T4632 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1557341 T4632 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1557341 T4632 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1557342 T4632 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1557342 T4632 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1557342 T4632 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1557343 T4632 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1557343 T4632 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1557344 T4632 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1557350 T4632 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1557354 T4632 oass.SolrIndexSearcher.<init> Opening Searcher@2f3e0328 main
[junit4:junit4] 2> 1557355 T4632 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1369947787048/control/data/tlog
[junit4:junit4] 2> 1557356 T4632 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1557356 T4632 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1557359 T4633 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2f3e0328 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1557360 T4632 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1557361 T4632 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1558045 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1558046 T4630 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:55609_ao_dxt%2Fc",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55609/ao_dxt/c"}
[junit4:junit4] 2> 1558046 T4630 oasc.Overseer$ClusterStateUpdater.createCollection Create collection control_collection with numShards 1
[junit4:junit4] 2> 1558046 T4630 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1558062 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 1558363 T4632 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1558363 T4632 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:55609/ao_dxt/c collection:control_collection shard:shard1
[junit4:junit4] 2> 1558364 T4632 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leader_elect/shard1/election
[junit4:junit4] 2> 1558414 T4632 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1558439 T4632 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1558439 T4632 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1558440 T4632 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:55609/ao_dxt/c/collection1/
[junit4:junit4] 2> 1558440 T4632 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1558440 T4632 oasc.SyncStrategy.syncToMe http://127.0.0.1:55609/ao_dxt/c/collection1/ has no replicas
[junit4:junit4] 2> 1558440 T4632 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:55609/ao_dxt/c/collection1/
[junit4:junit4] 2> 1558441 T4632 oascc.SolrZkClient.makePath makePath: /collections/control_collection/leaders/shard1
[junit4:junit4] 2> 1559565 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1559596 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 1)
[junit4:junit4] 2> 1559637 T4632 oasc.ZkController.register We are http://127.0.0.1:55609/ao_dxt/c/collection1/ and leader is http://127.0.0.1:55609/ao_dxt/c/collection1/
[junit4:junit4] 2> 1559637 T4632 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:55609/ao_dxt/c
[junit4:junit4] 2> 1559637 T4632 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1559637 T4632 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1559638 T4632 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1559640 T4632 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1559641 T4607 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1559642 T4607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1559642 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1559658 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:
[junit4:junit4] 2> 1559660 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1559662 T4636 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@4ede96c2 name:ZooKeeperConnection Watcher:127.0.0.1:29787/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1559662 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1559663 T4607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1559666 T4607 oasc.ChaosMonkey.monkeyLog monkey: init - expire sessions:true cause connection loss:true
[junit4:junit4] 2> 1559912 T4607 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1559916 T4607 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:58798
[junit4:junit4] 2> 1559917 T4607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1559917 T4607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1559918 T4607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1369947790973
[junit4:junit4] 2> 1559918 T4607 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1369947790973/solr.xml
[junit4:junit4] 2> 1559919 T4607 oasc.CoreContainer.<init> New CoreContainer 915427914
[junit4:junit4] 2> 1559920 T4607 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1369947790973/'
[junit4:junit4] 2> 1559920 T4607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1369947790973/'
[junit4:junit4] 2> 1560032 T4607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1560032 T4607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1560033 T4607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1560034 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1560034 T4607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1560035 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1560035 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1560036 T4607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1560036 T4607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1560037 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1560054 T4607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1560054 T4607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:29787/solr
[junit4:junit4] 2> 1560055 T4607 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1560056 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1560059 T4647 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@18b985d name:ZooKeeperConnection Watcher:127.0.0.1:29787 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1560060 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1560076 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1560088 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1560090 T4649 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@67d5ad4a name:ZooKeeperConnection Watcher:127.0.0.1:29787/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1560091 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1560100 T4607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1561104 T4607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58798_ao_dxt%2Fc
[junit4:junit4] 2> 1561106 T4607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:58798_ao_dxt%2Fc
[junit4:junit4] 2> 1561110 T4629 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1561110 T4649 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1561110 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 1561110 T4636 oascc.ZkStateReader$3.process Updating live nodes... (2)
[junit4:junit4] 2> 1561122 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1561123 T4630 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=1 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"1",
[junit4:junit4] 2> "numShards":"1",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"control_collection",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:55609_ao_dxt%2Fc",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:55609/ao_dxt/c"}
[junit4:junit4] 2> 1561126 T4650 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1369947790973/collection1
[junit4:junit4] 2> 1561126 T4650 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1561130 T4650 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1561131 T4650 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1561131 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 1561131 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 1561131 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 1561133 T4650 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1369947790973/collection1/'
[junit4:junit4] 2> 1561134 T4650 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1369947790973/collection1/lib/README' to classloader
[junit4:junit4] 2> 1561135 T4650 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty1-1369947790973/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1561195 T4650 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1561253 T4650 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1561356 T4650 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1561363 T4650 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1561920 T4650 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1561925 T4650 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1561927 T4650 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1561932 T4650 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1561955 T4650 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1561956 T4650 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty1-1369947790973/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty1/
[junit4:junit4] 2> 1561956 T4650 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c2bfdff
[junit4:junit4] 2> 1561957 T4650 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1561957 T4650 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty1
[junit4:junit4] 2> 1561958 T4650 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty1/index/
[junit4:junit4] 2> 1561958 T4650 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty1/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1561958 T4650 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty1/index
[junit4:junit4] 2> 1561962 T4650 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59bb6c6c lockFactory=org.apache.lucene.store.NativeFSLockFactory@41b8cbfe),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1561962 T4650 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1561966 T4650 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1561966 T4650 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1561967 T4650 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1561968 T4650 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1561969 T4650 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1561969 T4650 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1561969 T4650 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1561970 T4650 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1561971 T4650 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1561980 T4650 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1561987 T4650 oass.SolrIndexSearcher.<init> Opening Searcher@46fa75c6 main
[junit4:junit4] 2> 1561988 T4650 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty1/tlog
[junit4:junit4] 2> 1561989 T4650 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1561989 T4650 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1561996 T4651 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@46fa75c6 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1562000 T4650 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1562000 T4650 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1562641 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1562642 T4630 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:58798_ao_dxt%2Fc",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58798/ao_dxt/c"}
[junit4:junit4] 2> 1562642 T4630 oasc.Overseer$ClusterStateUpdater.createCollection Create collection collection1 with numShards 2
[junit4:junit4] 2> 1562643 T4630 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1562657 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 1562657 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 1562657 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 1563003 T4650 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1563003 T4650 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:58798/ao_dxt/c collection:collection1 shard:shard1
[junit4:junit4] 2> 1563004 T4650 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard1/election
[junit4:junit4] 2> 1563022 T4650 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1563025 T4650 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1563025 T4650 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1563025 T4650 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:58798/ao_dxt/c/collection1/
[junit4:junit4] 2> 1563025 T4650 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1563026 T4650 oasc.SyncStrategy.syncToMe http://127.0.0.1:58798/ao_dxt/c/collection1/ has no replicas
[junit4:junit4] 2> 1563026 T4650 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:58798/ao_dxt/c/collection1/
[junit4:junit4] 2> 1563026 T4650 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard1
[junit4:junit4] 2> 1564161 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1564190 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 1564190 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 1564190 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 1564206 T4650 oasc.ZkController.register We are http://127.0.0.1:58798/ao_dxt/c/collection1/ and leader is http://127.0.0.1:58798/ao_dxt/c/collection1/
[junit4:junit4] 2> 1564206 T4650 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:58798/ao_dxt/c
[junit4:junit4] 2> 1564206 T4650 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1564206 T4650 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1564207 T4650 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1564209 T4650 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1564211 T4607 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1564211 T4607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1564212 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1564473 T4607 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1564477 T4607 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:24236
[junit4:junit4] 2> 1564478 T4607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1564479 T4607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1564479 T4607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1369947795534
[junit4:junit4] 2> 1564480 T4607 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1369947795534/solr.xml
[junit4:junit4] 2> 1564480 T4607 oasc.CoreContainer.<init> New CoreContainer 930169961
[junit4:junit4] 2> 1564481 T4607 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1369947795534/'
[junit4:junit4] 2> 1564481 T4607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1369947795534/'
[junit4:junit4] 2> 1564597 T4607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1564598 T4607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1564599 T4607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1564599 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1564600 T4607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1564600 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1564601 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1564601 T4607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1564602 T4607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1564603 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1564621 T4607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1564622 T4607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:29787/solr
[junit4:junit4] 2> 1564622 T4607 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1564623 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1564627 T4663 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2232244c name:ZooKeeperConnection Watcher:127.0.0.1:29787 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1564627 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1564643 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1564654 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1564656 T4665 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@3b281c18 name:ZooKeeperConnection Watcher:127.0.0.1:29787/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1564656 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1564667 T4607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1565670 T4607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:24236_ao_dxt%2Fc
[junit4:junit4] 2> 1565673 T4607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:24236_ao_dxt%2Fc
[junit4:junit4] 2> 1565677 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 2)
[junit4:junit4] 2> 1565677 T4629 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1565677 T4665 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1565677 T4636 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1565677 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1565678 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1565678 T4649 oascc.ZkStateReader$3.process Updating live nodes... (3)
[junit4:junit4] 2> 1565694 T4666 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1369947795534/collection1
[junit4:junit4] 2> 1565694 T4666 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1565695 T4666 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1565696 T4666 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1565697 T4666 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1369947795534/collection1/'
[junit4:junit4] 2> 1565699 T4666 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1369947795534/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1565699 T4666 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty2-1369947795534/collection1/lib/README' to classloader
[junit4:junit4] 2> 1565704 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1565704 T4630 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"2",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:58798_ao_dxt%2Fc",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:58798/ao_dxt/c"}
[junit4:junit4] 2> 1565713 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1565714 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1565714 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1565713 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1565752 T4666 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1565811 T4666 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1565913 T4666 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1565921 T4666 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1566490 T4666 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1566494 T4666 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1566497 T4666 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1566502 T4666 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1566524 T4666 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1566525 T4666 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty2-1369947795534/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty2/
[junit4:junit4] 2> 1566525 T4666 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c2bfdff
[junit4:junit4] 2> 1566526 T4666 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1566526 T4666 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty2
[junit4:junit4] 2> 1566527 T4666 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty2/index/
[junit4:junit4] 2> 1566527 T4666 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty2/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1566527 T4666 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty2/index
[junit4:junit4] 2> 1566531 T4666 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2f5059b3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a1574c5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1566531 T4666 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1566535 T4666 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1566535 T4666 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1566536 T4666 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1566537 T4666 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1566538 T4666 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1566538 T4666 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1566539 T4666 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1566539 T4666 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1566540 T4666 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1566550 T4666 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1566557 T4666 oass.SolrIndexSearcher.<init> Opening Searcher@57ada620 main
[junit4:junit4] 2> 1566557 T4666 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty2/tlog
[junit4:junit4] 2> 1566559 T4666 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1566559 T4666 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1566566 T4667 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@57ada620 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1566569 T4666 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1566569 T4666 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1567225 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1567225 T4630 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:24236_ao_dxt%2Fc",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:24236/ao_dxt/c"}
[junit4:junit4] 2> 1567226 T4630 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 1567226 T4630 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 1567240 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1567241 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1567241 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1567241 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1567572 T4666 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1567572 T4666 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:24236/ao_dxt/c collection:collection1 shard:shard2
[junit4:junit4] 2> 1567573 T4666 oascc.SolrZkClient.makePath makePath: /collections/collection1/leader_elect/shard2/election
[junit4:junit4] 2> 1567590 T4666 oasc.ShardLeaderElectionContext.runLeaderProcess Running the leader process.
[junit4:junit4] 2> 1567597 T4666 oasc.ShardLeaderElectionContext.waitForReplicasToComeUp Enough replicas found to continue.
[junit4:junit4] 2> 1567597 T4666 oasc.ShardLeaderElectionContext.runLeaderProcess I may be the new leader - try and sync
[junit4:junit4] 2> 1567598 T4666 oasc.SyncStrategy.sync Sync replicas to http://127.0.0.1:24236/ao_dxt/c/collection1/
[junit4:junit4] 2> 1567598 T4666 oasc.SyncStrategy.syncReplicas Sync Success - now sync replicas to me
[junit4:junit4] 2> 1567598 T4666 oasc.SyncStrategy.syncToMe http://127.0.0.1:24236/ao_dxt/c/collection1/ has no replicas
[junit4:junit4] 2> 1567599 T4666 oasc.ShardLeaderElectionContext.runLeaderProcess I am the new leader: http://127.0.0.1:24236/ao_dxt/c/collection1/
[junit4:junit4] 2> 1567599 T4666 oascc.SolrZkClient.makePath makePath: /collections/collection1/leaders/shard2
[junit4:junit4] 2> 1568745 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1568774 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1568775 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1568775 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1568775 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1568836 T4666 oasc.ZkController.register We are http://127.0.0.1:24236/ao_dxt/c/collection1/ and leader is http://127.0.0.1:24236/ao_dxt/c/collection1/
[junit4:junit4] 2> 1568836 T4666 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:24236/ao_dxt/c
[junit4:junit4] 2> 1568836 T4666 oasc.ZkController.checkRecovery I am the leader, no recovery necessary
[junit4:junit4] 2> 1568837 T4666 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1568837 T4666 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1568839 T4666 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1568840 T4607 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1568841 T4607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1568841 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1569024 T4607 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1569028 T4607 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:42801
[junit4:junit4] 2> 1569028 T4607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1569029 T4607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1569029 T4607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1369947800159
[junit4:junit4] 2> 1569030 T4607 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1369947800159/solr.xml
[junit4:junit4] 2> 1569030 T4607 oasc.CoreContainer.<init> New CoreContainer 473177812
[junit4:junit4] 2> 1569030 T4607 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1369947800159/'
[junit4:junit4] 2> 1569031 T4607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1369947800159/'
[junit4:junit4] 2> 1569113 T4607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1569114 T4607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1569114 T4607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1569114 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1569115 T4607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1569115 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1569115 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1569116 T4607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1569116 T4607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1569116 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1569128 T4607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1569128 T4607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:29787/solr
[junit4:junit4] 2> 1569129 T4607 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1569130 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1569136 T4679 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@231b8a03 name:ZooKeeperConnection Watcher:127.0.0.1:29787 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1569153 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1569156 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1569168 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1569170 T4681 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@2f047733 name:ZooKeeperConnection Watcher:127.0.0.1:29787/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1569170 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1569182 T4607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1570186 T4607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:42801_ao_dxt%2Fc
[junit4:junit4] 2> 1570198 T4607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:42801_ao_dxt%2Fc
[junit4:junit4] 2> 1570215 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1570217 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1570217 T4681 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1570217 T4629 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1570217 T4636 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1570218 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1570218 T4665 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1570218 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1570219 T4649 oascc.ZkStateReader$3.process Updating live nodes... (4)
[junit4:junit4] 2> 1570224 T4682 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1369947800159/collection1
[junit4:junit4] 2> 1570225 T4682 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1570225 T4682 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1570226 T4682 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1570227 T4682 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1369947800159/collection1/'
[junit4:junit4] 2> 1570228 T4682 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1369947800159/collection1/lib/README' to classloader
[junit4:junit4] 2> 1570229 T4682 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty3-1369947800159/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1570281 T4682 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1570293 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1570294 T4630 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"3",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:24236_ao_dxt%2Fc",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:24236/ao_dxt/c"}
[junit4:junit4] 2> 1570306 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1570306 T4681 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1570306 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1570306 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1570306 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1570340 T4682 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1570443 T4682 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1570450 T4682 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1571374 T3 oasc.CoreContainer.finalize ERROR CoreContainer was not shutdown prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!! instance=852026526
[junit4:junit4] 2> 1571375 T3 oasc.CoreContainer.finalize ERROR CoreContainer was not shutdown prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!! instance=870562843
[junit4:junit4] 2> 1571375 T3 oasc.CoreContainer.finalize ERROR CoreContainer was not shutdown prior to finalize(), indicates a bug -- POSSIBLE RESOURCE LEAK!!! instance=1177524935
[junit4:junit4] 2> 1571560 T4682 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1571563 T4682 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1571565 T4682 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1571569 T4682 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1571587 T4682 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1571588 T4682 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty3-1369947800159/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty3/
[junit4:junit4] 2> 1571588 T4682 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c2bfdff
[junit4:junit4] 2> 1571588 T4682 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1571589 T4682 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty3
[junit4:junit4] 2> 1571589 T4682 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty3/index/
[junit4:junit4] 2> 1571589 T4682 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty3/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1571590 T4682 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty3/index
[junit4:junit4] 2> 1571592 T4682 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1349bf37 lockFactory=org.apache.lucene.store.NativeFSLockFactory@44e00683),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1571592 T4682 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1571595 T4682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1571595 T4682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1571596 T4682 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1571596 T4682 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1571597 T4682 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1571597 T4682 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1571597 T4682 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1571598 T4682 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1571598 T4682 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1571606 T4682 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1571611 T4682 oass.SolrIndexSearcher.<init> Opening Searcher@3bbcaca5 main
[junit4:junit4] 2> 1571612 T4682 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty3/tlog
[junit4:junit4] 2> 1571612 T4682 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1571613 T4682 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1571618 T4683 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@3bbcaca5 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1571620 T4682 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1571621 T4682 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1571812 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1571813 T4630 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42801_ao_dxt%2Fc",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42801/ao_dxt/c"}
[junit4:junit4] 2> 1571813 T4630 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 1571813 T4630 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard1
[junit4:junit4] 2> 1571826 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1571826 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1571826 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1571826 T4681 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1571826 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1572623 T4682 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1572623 T4682 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:42801/ao_dxt/c collection:collection1 shard:shard1
[junit4:junit4] 2> 1572626 T4682 oasc.ZkController.register We are http://127.0.0.1:42801/ao_dxt/c/collection1/ and leader is http://127.0.0.1:58798/ao_dxt/c/collection1/
[junit4:junit4] 2> 1572627 T4682 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:42801/ao_dxt/c
[junit4:junit4] 2> 1572627 T4682 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 1572627 T4682 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C3012 name=collection1 org.apache.solr.core.SolrCore@6735edb1 url=http://127.0.0.1:42801/ao_dxt/c/collection1 node=127.0.0.1:42801_ao_dxt%2Fc C3012_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:42801_ao_dxt%2Fc, base_url=http://127.0.0.1:42801/ao_dxt/c}
[junit4:junit4] 2> 1572628 T4684 C3012 P42801 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 1572628 T4682 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1572629 T4684 C3012 P42801 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1572629 T4684 C3012 P42801 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 1572629 T4684 C3012 P42801 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1572630 T4607 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1572631 T4607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1572631 T4684 C3012 P42801 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1572631 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1572650 T4639 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1572914 T4607 oejs.Server.doStart jetty-8.1.10.v20130312
[junit4:junit4] 2> 1572917 T4607 oejs.AbstractConnector.doStart Started SocketConnector@127.0.0.1:32595
[junit4:junit4] 2> 1572918 T4607 oass.SolrDispatchFilter.init SolrDispatchFilter.init()
[junit4:junit4] 2> 1572918 T4607 oasc.SolrResourceLoader.locateSolrHome JNDI not configured for solr (NoInitialContextEx)
[junit4:junit4] 2> 1572919 T4607 oasc.SolrResourceLoader.locateSolrHome using system property solr.solr.home: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1369947803956
[junit4:junit4] 2> 1572919 T4607 oasc.CoreContainer$Initializer.initialize looking for solr config file: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1369947803956/solr.xml
[junit4:junit4] 2> 1572920 T4607 oasc.CoreContainer.<init> New CoreContainer 1521286617
[junit4:junit4] 2> 1572920 T4607 oasc.CoreContainer.load Loading CoreContainer using Solr Home: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1369947803956/'
[junit4:junit4] 2> 1572921 T4607 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1369947803956/'
[junit4:junit4] 2> 1573042 T4607 oashc.HttpShardHandlerFactory.getParameter Setting socketTimeout to: 120000
[junit4:junit4] 2> 1573043 T4607 oashc.HttpShardHandlerFactory.getParameter Setting urlScheme to: http://
[junit4:junit4] 2> 1573043 T4607 oashc.HttpShardHandlerFactory.getParameter Setting connTimeout to: 15000
[junit4:junit4] 2> 1573044 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maxConnectionsPerHost to: 20
[junit4:junit4] 2> 1573044 T4607 oashc.HttpShardHandlerFactory.getParameter Setting corePoolSize to: 0
[junit4:junit4] 2> 1573045 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maximumPoolSize to: 2147483647
[junit4:junit4] 2> 1573045 T4607 oashc.HttpShardHandlerFactory.getParameter Setting maxThreadIdleTime to: 5
[junit4:junit4] 2> 1573046 T4607 oashc.HttpShardHandlerFactory.getParameter Setting sizeOfQueue to: -1
[junit4:junit4] 2> 1573046 T4607 oashc.HttpShardHandlerFactory.getParameter Setting fairnessPolicy to: false
[junit4:junit4] 2> 1573047 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnectionsPerHost=20&maxConnections=10000&socketTimeout=120000&connTimeout=15000&retry=false
[junit4:junit4] 2> 1573063 T4607 oasl.LogWatcher.newRegisteredLogWatcher Registering Log Listener
[junit4:junit4] 2> 1573064 T4607 oasc.ZkContainer.initZooKeeper Zookeeper client=127.0.0.1:29787/solr
[junit4:junit4] 2> 1573065 T4607 oasc.ZkController.checkChrootPath zkHost includes chroot
[junit4:junit4] 2> 1573066 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1573069 T4696 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@5db185fd name:ZooKeeperConnection Watcher:127.0.0.1:29787 got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1573070 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1573085 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=500&maxConnectionsPerHost=16&socketTimeout=120000&connTimeout=15000
[junit4:junit4] 2> 1573096 T4607 oascc.ConnectionManager.waitForConnected Waiting for client to connect to ZooKeeper
[junit4:junit4] 2> 1573098 T4698 oascc.ConnectionManager.process Watcher org.apache.solr.common.cloud.ConnectionManager@9dbcbda name:ZooKeeperConnection Watcher:127.0.0.1:29787/solr got event WatchedEvent state:SyncConnected type:None path:null path:null type:None
[junit4:junit4] 2> 1573098 T4607 oascc.ConnectionManager.waitForConnected Client is connected to ZooKeeper
[junit4:junit4] 2> 1573107 T4607 oascc.ZkStateReader.createClusterStateWatchersAndUpdate Updating cluster state from ZooKeeper...
[junit4:junit4] 2> 1573338 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1573339 T4630 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42801_ao_dxt%2Fc",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42801/ao_dxt/c"}
[junit4:junit4] 2> 1573394 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1573394 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1573394 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1573394 T4681 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1573394 T4698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1573394 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1573651 T4639 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 4, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 1573651 T4639 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=4&state=recovering&nodeName=127.0.0.1:42801_ao_dxt%252Fc&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1001
[junit4:junit4] 2> 1574111 T4607 oasc.ZkController.createEphemeralLiveNode Register node as live in ZooKeeper:/live_nodes/127.0.0.1:32595_ao_dxt%2Fc
[junit4:junit4] 2> 1574113 T4607 oascc.SolrZkClient.makePath makePath: /live_nodes/127.0.0.1:32595_ao_dxt%2Fc
[junit4:junit4] 2> 1574116 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1574116 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1574116 T4629 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1574116 T4698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 4)
[junit4:junit4] 2> 1574117 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1574116 T4681 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1574116 T4636 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1574118 T4665 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1574118 T4649 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1574118 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1574117 T4681 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1574130 T4698 oascc.ZkStateReader$3.process Updating live nodes... (5)
[junit4:junit4] 2> 1574135 T4699 oasc.CoreContainer.create Creating SolrCore 'collection1' using instanceDir: /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1369947803956/collection1
[junit4:junit4] 2> 1574135 T4699 oasc.ZkController.createCollectionZkNode Check for collection zkNode:collection1
[junit4:junit4] 2> 1574136 T4699 oasc.ZkController.createCollectionZkNode Collection zkNode exists
[junit4:junit4] 2> 1574136 T4699 oasc.ZkController.readConfigName Load collection config from:/collections/collection1
[junit4:junit4] 2> 1574138 T4699 oasc.SolrResourceLoader.<init> new SolrResourceLoader for directory: '/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1369947803956/collection1/'
[junit4:junit4] 2> 1574140 T4699 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty4-1369947803956/collection1/lib/README' to classloader
[junit4:junit4] 2> 1574140 T4699 oasc.SolrResourceLoader.replaceClassLoader Adding 'file:/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/org.apache.solr.cloud.ShardSplitTest-jetty4-1369947803956/collection1/lib/classes/' to classloader
[junit4:junit4] 2> 1574202 T4699 oasc.SolrConfig.<init> Using Lucene MatchVersion: LUCENE_44
[junit4:junit4] 2> 1574272 T4699 oasc.SolrConfig.<init> Loaded SolrConfig: solrconfig.xml
[junit4:junit4] 2> 1574375 T4699 oass.IndexSchema.readSchema Reading Solr Schema from schema.xml
[junit4:junit4] 2> 1574382 T4699 oass.IndexSchema.readSchema [collection1] Schema name=test
[junit4:junit4] 2> 1574994 T4699 oass.IndexSchema.readSchema default search field in schema is text
[junit4:junit4] 2> 1574999 T4699 oass.IndexSchema.readSchema unique key field: id
[junit4:junit4] 2> 1575001 T4699 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1575007 T4699 oass.FileExchangeRateProvider.reload Reloading exchange rates from file currency.xml
[junit4:junit4] 2> 1575026 T4699 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1575027 T4699 oasc.SolrCore.<init> [collection1] Opening new SolrCore at /usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0/./org.apache.solr.cloud.ShardSplitTest-jetty4-1369947803956/collection1/, dataDir=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/
[junit4:junit4] 2> 1575027 T4699 oasc.JmxMonitoredMap.<init> JMX monitoring is enabled. Adding Solr mbeans to JMX Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5c2bfdff
[junit4:junit4] 2> 1575028 T4699 oasc.SolrCore.initDirectoryFactory org.apache.solr.core.MockDirectoryFactory
[junit4:junit4] 2> 1575029 T4699 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4
[junit4:junit4] 2> 1575029 T4699 oasc.SolrCore.getNewIndexDir New index directory detected: old=null new=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/index/
[junit4:junit4] 2> 1575029 T4699 oasc.SolrCore.initIndex WARN [collection1] Solr index directory './org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/index' doesn't exist. Creating new index...
[junit4:junit4] 2> 1575030 T4699 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/index
[junit4:junit4] 2> 1575033 T4699 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d2a7ade lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e4b0472),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1575034 T4699 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1575037 T4699 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "dedupe"
[junit4:junit4] 2> 1575037 T4699 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "stored_sig"
[junit4:junit4] 2> 1575038 T4699 oasup.UpdateRequestProcessorChain.init inserting DistributedUpdateProcessorFactory into updateRequestProcessorChain "distrib-dup-test-chain-implicit"
[junit4:junit4] 2> 1575039 T4699 oasc.RequestHandlers.initHandlersFromConfig created standard: solr.StandardRequestHandler
[junit4:junit4] 2> 1575040 T4699 oasc.RequestHandlers.initHandlersFromConfig created /get: solr.RealTimeGetHandler
[junit4:junit4] 2> 1575040 T4699 oasc.RequestHandlers.initHandlersFromConfig adding lazy requestHandler: solr.ReplicationHandler
[junit4:junit4] 2> 1575040 T4699 oasc.RequestHandlers.initHandlersFromConfig created /replication: solr.ReplicationHandler
[junit4:junit4] 2> 1575041 T4699 oasc.RequestHandlers.initHandlersFromConfig created /update: solr.UpdateRequestHandler
[junit4:junit4] 2> 1575042 T4699 oasc.RequestHandlers.initHandlersFromConfig created /admin/: org.apache.solr.handler.admin.AdminHandlers
[junit4:junit4] 2> 1575051 T4699 oashl.XMLLoader.init xsltCacheLifetimeSeconds=60
[junit4:junit4] 2> 1575058 T4699 oass.SolrIndexSearcher.<init> Opening Searcher@2bc60133 main
[junit4:junit4] 2> 1575059 T4699 oasu.UpdateHandler.clearLog Clearing tlog files, tlogDir=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/tlog
[junit4:junit4] 2> 1575060 T4699 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4:junit4] 2> 1575060 T4699 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4:junit4] 2> 1575065 T4700 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2bc60133 main{StandardDirectoryReader(segments_1:1)}
[junit4:junit4] 2> 1575068 T4699 oasc.ZkController.publish publishing core=collection1 state=down
[junit4:junit4] 2> 1575068 T4699 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> ASYNC NEW_CORE C3013 name=collection1 org.apache.solr.core.SolrCore@6735edb1 url=http://127.0.0.1:42801/ao_dxt/c/collection1 node=127.0.0.1:42801_ao_dxt%2Fc C3013_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:42801_ao_dxt%2Fc, base_url=http://127.0.0.1:42801/ao_dxt/c}
[junit4:junit4] 2> 1575653 T4684 C3013 P42801 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:58798/ao_dxt/c/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 1575653 T4684 C3013 P42801 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:42801/ao_dxt/c START replicas=[http://127.0.0.1:58798/ao_dxt/c/collection1/] nUpdates=100
[junit4:junit4] 2> 1575654 T4684 C3013 P42801 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 1575654 T4684 C3013 P42801 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 1575654 T4684 C3013 P42801 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 1575654 T4684 C3013 P42801 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 1575654 T4684 C3013 P42801 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 1575654 T4684 C3013 P42801 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:58798/ao_dxt/c/collection1/. core=collection1
[junit4:junit4] 2> 1575655 T4684 C3013 P42801 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> ASYNC NEW_CORE C3014 name=collection1 org.apache.solr.core.SolrCore@a61feac url=http://127.0.0.1:58798/ao_dxt/c/collection1 node=127.0.0.1:58798_ao_dxt%2Fc C3014_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:58798_ao_dxt%2Fc, base_url=http://127.0.0.1:58798/ao_dxt/c, leader=true}
[junit4:junit4] 2> 1575660 T4640 C3014 P58798 oasc.SolrCore.execute [collection1] webapp=/ao_dxt/c path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=0
[junit4:junit4] 2> 1575669 T4641 C3014 P58798 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1575671 T4641 C3014 P58798 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59bb6c6c lockFactory=org.apache.lucene.store.NativeFSLockFactory@41b8cbfe),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1575671 T4641 C3014 P58798 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1575672 T4641 C3014 P58798 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59bb6c6c lockFactory=org.apache.lucene.store.NativeFSLockFactory@41b8cbfe),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59bb6c6c lockFactory=org.apache.lucene.store.NativeFSLockFactory@41b8cbfe),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1575672 T4641 C3014 P58798 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1575673 T4641 C3014 P58798 oass.SolrIndexSearcher.<init> Opening Searcher@38032b2b realtime
[junit4:junit4] 2> 1575673 T4641 C3014 P58798 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1575673 T4641 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 4
[junit4:junit4] 2> 1575674 T4684 C3013 P42801 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1575674 T4684 C3013 P42801 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 1575675 T4642 C3014 P58798 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1575676 T4642 C3014 P58798 oasc.SolrCore.execute [collection1] webapp=/ao_dxt/c path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 1575676 T4684 C3013 P42801 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 1575676 T4684 C3013 P42801 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 1575676 T4684 C3013 P42801 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 1575679 T4642 C3014 P58798 oasc.SolrCore.execute [collection1] webapp=/ao_dxt/c path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 1575679 T4684 C3013 P42801 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 1575680 T4684 C3013 P42801 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty3/index.20130531000326987
[junit4:junit4] 2> 1575680 T4684 C3013 P42801 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@28a1949 lockFactory=org.apache.lucene.store.NativeFSLockFactory@6526b2b5) fullCopy=false
[junit4:junit4] 2> 1575683 T4642 C3014 P58798 oasc.SolrCore.execute [collection1] webapp=/ao_dxt/c path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 1575684 T4684 C3013 P42801 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 1575684 T4684 C3013 P42801 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1575685 T4684 C3013 P42801 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 1575686 T4684 C3013 P42801 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1349bf37 lockFactory=org.apache.lucene.store.NativeFSLockFactory@44e00683),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1349bf37 lockFactory=org.apache.lucene.store.NativeFSLockFactory@44e00683),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1575687 T4684 C3013 P42801 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1575687 T4684 C3013 P42801 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1575687 T4684 C3013 P42801 oass.SolrIndexSearcher.<init> Opening Searcher@da5e067 main
[junit4:junit4] 2> 1575688 T4683 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@da5e067 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1575688 T4684 C3013 P42801 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty3/index.20130531000326987 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty3/index.20130531000326987;done=true>>]
[junit4:junit4] 2> 1575688 T4684 C3013 P42801 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty3/index.20130531000326987
[junit4:junit4] 2> 1575689 T4684 C3013 P42801 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty3/index.20130531000326987
[junit4:junit4] 2> 1575689 T4684 C3013 P42801 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 1575689 T4684 C3013 P42801 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 1575689 T4684 C3013 P42801 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1575689 T4684 C3013 P42801 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1575691 T4684 C3013 P42801 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 1576401 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1576402 T4630 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":null,
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"down",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:32595_ao_dxt%2Fc",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:32595/ao_dxt/c"}
[junit4:junit4] 2> 1576403 T4630 oasc.Overseer$ClusterStateUpdater.updateState Collection already exists with numShards=2
[junit4:junit4] 2> 1576403 T4630 oasc.Overseer$ClusterStateUpdater.updateState Assigning new node to shard=shard2
[junit4:junit4] 2> 1576407 T4630 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"4",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard1",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:42801_ao_dxt%2Fc",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:42801/ao_dxt/c"}
[junit4:junit4] 2> 1576419 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1576419 T4681 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1576419 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1576419 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1576419 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1576419 T4698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1577073 T4699 oasc.CoreContainer.registerCore registering core: collection1
[junit4:junit4] 2> 1577073 T4699 oasc.ZkController.register Register replica - core:collection1 address:http://127.0.0.1:32595/ao_dxt/c collection:collection1 shard:shard2
[junit4:junit4] 2> 1577076 T4699 oasc.ZkController.register We are http://127.0.0.1:32595/ao_dxt/c/collection1/ and leader is http://127.0.0.1:24236/ao_dxt/c/collection1/
[junit4:junit4] 2> 1577077 T4699 oasc.ZkController.register No LogReplay needed for core=collection1 baseURL=http://127.0.0.1:32595/ao_dxt/c
[junit4:junit4] 2> 1577077 T4699 oasc.ZkController.checkRecovery Core needs to recover:collection1
[junit4:junit4] 2> 1577077 T4699 oasu.DefaultSolrCoreState.doRecovery Running recovery - first canceling any ongoing recovery
[junit4:junit4] 2> ASYNC NEW_CORE C3015 name=collection1 org.apache.solr.core.SolrCore@485b806a url=http://127.0.0.1:32595/ao_dxt/c/collection1 node=127.0.0.1:32595_ao_dxt%2Fc C3015_STATE=coll:collection1 core:collection1 props:{state=down, core=collection1, collection=collection1, node_name=127.0.0.1:32595_ao_dxt%2Fc, base_url=http://127.0.0.1:32595/ao_dxt/c}
[junit4:junit4] 2> 1577077 T4703 C3015 P32595 oasc.RecoveryStrategy.run Starting recovery process. core=collection1 recoveringAfterStartup=true
[junit4:junit4] 2> 1577078 T4699 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1577078 T4703 C3015 P32595 oasc.RecoveryStrategy.doRecovery ###### startupVersions=[]
[junit4:junit4] 2> 1577079 T4703 C3015 P32595 oasc.ZkController.publish publishing core=collection1 state=recovering
[junit4:junit4] 2> 1577079 T4703 C3015 P32595 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1577079 T4607 oass.SolrDispatchFilter.init user.dir=/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build/solr-core/test/J0
[junit4:junit4] 2> 1577080 T4607 oass.SolrDispatchFilter.init SolrDispatchFilter.init() done
[junit4:junit4] 2> 1577080 T4703 C3015 P32595 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1577081 T4607 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1577094 T4607 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1577094 T4655 oasha.CoreAdminHandler.handleWaitForStateAction Going to wait for coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true
[junit4:junit4] 2> 1577095 T4607 oasc.AbstractFullDistribZkTestBase.waitForThingsToLevelOut Wait for recoveries to finish - wait 15 for each attempt
[junit4:junit4] 2> 1577096 T4607 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):15
[junit4:junit4] 2> 1577096 T4607 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1577933 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1577934 T4630 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"recovering",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:32595_ao_dxt%2Fc",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:32595/ao_dxt/c"}
[junit4:junit4] 2> 1577946 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1577946 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1577946 T4681 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1577946 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1577946 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1577946 T4698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1578096 T4655 oasha.CoreAdminHandler.handleWaitForStateAction Waited coreNodeName: 5, state: recovering, checkLive: true, onlyIfLeader: true for: 1 seconds.
[junit4:junit4] 2> 1578096 T4655 oass.SolrDispatchFilter.handleAdminRequest [admin] webapp=null path=/admin/cores params={coreNodeName=5&state=recovering&nodeName=127.0.0.1:32595_ao_dxt%252Fc&action=PREPRECOVERY&checkLive=true&core=collection1&wt=javabin&onlyIfLeader=true&version=2} status=0 QTime=1002
[junit4:junit4] 2> 1578098 T4607 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1579100 T4607 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> C3015_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=recovering, core=collection1, collection=collection1, node_name=127.0.0.1:32595_ao_dxt%2Fc, base_url=http://127.0.0.1:32595/ao_dxt/c}
[junit4:junit4] 2> 1580098 T4703 C3015 P32595 oasc.RecoveryStrategy.doRecovery Attempting to PeerSync from http://127.0.0.1:24236/ao_dxt/c/collection1/ core=collection1 - recoveringAfterStartup=true
[junit4:junit4] 2> 1580098 T4703 C3015 P32595 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:32595/ao_dxt/c START replicas=[http://127.0.0.1:24236/ao_dxt/c/collection1/] nUpdates=100
[junit4:junit4] 2> 1580099 T4703 C3015 P32595 oasu.PeerSync.sync WARN no frame of reference to tell of we've missed updates
[junit4:junit4] 2> 1580099 T4703 C3015 P32595 oasc.RecoveryStrategy.doRecovery PeerSync Recovery was not successful - trying replication. core=collection1
[junit4:junit4] 2> 1580099 T4703 C3015 P32595 oasc.RecoveryStrategy.doRecovery Starting Replication Recovery. core=collection1
[junit4:junit4] 2> 1580099 T4703 C3015 P32595 oasc.RecoveryStrategy.doRecovery Begin buffering updates. core=collection1
[junit4:junit4] 2> 1580100 T4703 C3015 P32595 oasu.UpdateLog.bufferUpdates Starting to buffer updates. FSUpdateLog{state=ACTIVE, tlog=null}
[junit4:junit4] 2> 1580100 T4703 C3015 P32595 oasc.RecoveryStrategy.replicate Attempting to replicate from http://127.0.0.1:24236/ao_dxt/c/collection1/. core=collection1
[junit4:junit4] 2> 1580100 T4703 C3015 P32595 oascsi.HttpClientUtil.createClient Creating new http client, config:maxConnections=128&maxConnectionsPerHost=32&followRedirects=false
[junit4:junit4] 2> 1580103 T4607 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> ASYNC NEW_CORE C3016 name=collection1 org.apache.solr.core.SolrCore@2561c605 url=http://127.0.0.1:24236/ao_dxt/c/collection1 node=127.0.0.1:24236_ao_dxt%2Fc C3016_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:24236_ao_dxt%2Fc, base_url=http://127.0.0.1:24236/ao_dxt/c, leader=true}
[junit4:junit4] 2> 1580107 T4656 C3016 P24236 oasc.SolrCore.execute [collection1] webapp=/ao_dxt/c path=/get params={getVersions=100&distrib=false&wt=javabin&qt=/get&version=2} status=0 QTime=1
[junit4:junit4] 2> 1580111 T4657 C3016 P24236 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=false,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1580113 T4657 C3016 P24236 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2f5059b3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a1574c5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1580114 T4657 C3016 P24236 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1580115 T4657 C3016 P24236 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2f5059b3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a1574c5),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2f5059b3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a1574c5),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1580116 T4657 C3016 P24236 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1580116 T4657 C3016 P24236 oass.SolrIndexSearcher.<init> Opening Searcher@4c70238f realtime
[junit4:junit4] 2> 1580117 T4657 C3016 P24236 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1580117 T4657 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={waitSearcher=true&openSearcher=false&commit=true&wt=javabin&commit_end_point=true&version=2&softCommit=false} {commit=} 0 6
[junit4:junit4] 2> 1580118 T4703 C3015 P32595 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1580118 T4703 C3015 P32595 oash.SnapPuller.<init> No value set for 'pollInterval'. Timer Task not started.
[junit4:junit4] 2> 1580120 T4658 C3016 P24236 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4:junit4] 2> 1580120 T4658 C3016 P24236 oasc.SolrCore.execute [collection1] webapp=/ao_dxt/c path=/replication params={command=indexversion&qt=/replication&wt=javabin&version=2} status=0 QTime=1
[junit4:junit4] 2> 1580121 T4703 C3015 P32595 oash.SnapPuller.fetchLatestIndex Master's generation: 2
[junit4:junit4] 2> 1580121 T4703 C3015 P32595 oash.SnapPuller.fetchLatestIndex Slave's generation: 1
[junit4:junit4] 2> 1580121 T4703 C3015 P32595 oash.SnapPuller.fetchLatestIndex Starting replication process
[junit4:junit4] 2> 1580123 T4658 C3016 P24236 oasc.SolrCore.execute [collection1] webapp=/ao_dxt/c path=/replication params={command=filelist&qt=/replication&wt=javabin&generation=2&version=2} status=0 QTime=0
[junit4:junit4] 2> 1580124 T4703 C3015 P32595 oash.SnapPuller.fetchLatestIndex Number of files in latest index in master: 1
[junit4:junit4] 2> 1580125 T4703 C3015 P32595 oasc.CachingDirectoryFactory.get return new directory for ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/index.20130531000331431
[junit4:junit4] 2> 1580125 T4703 C3015 P32595 oash.SnapPuller.fetchLatestIndex Starting download to MockDirWrapper(org.apache.lucene.store.RAMDirectory@6d758b05 lockFactory=org.apache.lucene.store.NativeFSLockFactory@55526d5d) fullCopy=false
[junit4:junit4] 2> 1580128 T4658 C3016 P24236 oasc.SolrCore.execute [collection1] webapp=/ao_dxt/c path=/replication params={file=segments_2&command=filecontent&checksum=true&wt=filestream&qt=/replication&generation=2} status=0 QTime=0
[junit4:junit4] 2> 1580129 T4703 C3015 P32595 oash.SnapPuller.fetchLatestIndex Total time taken for download : 0 secs
[junit4:junit4] 2> 1580130 T4703 C3015 P32595 oasu.DefaultSolrCoreState.newIndexWriter Creating new IndexWriter...
[junit4:junit4] 2> 1580130 T4703 C3015 P32595 oasu.DefaultSolrCoreState.newIndexWriter Waiting until IndexWriter is unused... core=collection1
[junit4:junit4] 2> 1580132 T4703 C3015 P32595 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d2a7ade lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e4b0472),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d2a7ade lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e4b0472),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1580132 T4703 C3015 P32595 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1580132 T4703 C3015 P32595 oasu.DefaultSolrCoreState.newIndexWriter New IndexWriter is ready to be used.
[junit4:junit4] 2> 1580133 T4703 C3015 P32595 oass.SolrIndexSearcher.<init> Opening Searcher@77063fe5 main
[junit4:junit4] 2> 1580134 T4700 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@77063fe5 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1580135 T4703 C3015 P32595 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/index.20130531000331431 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/index.20130531000331431;done=true>>]
[junit4:junit4] 2> 1580135 T4703 C3015 P32595 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/index.20130531000331431
[junit4:junit4] 2> 1580135 T4703 C3015 P32595 oasc.CachingDirectoryFactory.closeCacheValue Removing directory before core close: ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/index.20130531000331431
[junit4:junit4] 2> 1580135 T4703 C3015 P32595 oasc.RecoveryStrategy.replay No replay needed. core=collection1
[junit4:junit4] 2> 1580136 T4703 C3015 P32595 oasc.RecoveryStrategy.doRecovery Replication Recovery was successful - registering as Active. core=collection1
[junit4:junit4] 2> 1580136 T4703 C3015 P32595 oasc.ZkController.publish publishing core=collection1 state=active
[junit4:junit4] 2> 1580136 T4703 C3015 P32595 oasc.ZkController.publish numShards not found on descriptor - reading it from system property
[junit4:junit4] 2> 1580162 T4703 C3015 P32595 oasc.RecoveryStrategy.doRecovery Finished recovery process. core=collection1
[junit4:junit4] 2> 1580954 T4630 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1580954 T4630 oasc.Overseer$ClusterStateUpdater.updateState Update state numShards=2 message={
[junit4:junit4] 2> "operation":"state",
[junit4:junit4] 2> "core_node_name":"5",
[junit4:junit4] 2> "numShards":"2",
[junit4:junit4] 2> "shard":"shard2",
[junit4:junit4] 2> "roles":null,
[junit4:junit4] 2> "state":"active",
[junit4:junit4] 2> "shard_state":"active",
[junit4:junit4] 2> "core":"collection1",
[junit4:junit4] 2> "collection":"collection1",
[junit4:junit4] 2> "shard_range":null,
[junit4:junit4] 2> "node_name":"127.0.0.1:32595_ao_dxt%2Fc",
[junit4:junit4] 2> "base_url":"http://127.0.0.1:32595/ao_dxt/c"}
[junit4:junit4] 2> 1580968 T4665 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1580968 T4698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1580968 T4649 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1580968 T4636 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1580968 T4681 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1580968 T4629 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeDataChanged path:/clusterstate.json, has occurred - updating... (live nodes size: 5)
[junit4:junit4] 2> 1581105 T4607 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1581106 T4607 oasc.AbstractDistribZkTestBase.waitForRecoveriesToFinish Recoveries finished - collection: collection1
[junit4:junit4] 2> ASYNC NEW_CORE C3017 name=collection1 org.apache.solr.core.SolrCore@5120760b url=http://127.0.0.1:55609/ao_dxt/c/collection1 node=127.0.0.1:55609_ao_dxt%2Fc C3017_STATE=coll:control_collection core:collection1 props:{shard=shard1, state=active, core=collection1, collection=control_collection, node_name=127.0.0.1:55609_ao_dxt%2Fc, base_url=http://127.0.0.1:55609/ao_dxt/c, leader=true}
[junit4:junit4] 2> 1581116 T4619 C3017 P55609 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1581119 T4619 C3017 P55609 oasc.SolrDeletionPolicy.onInit SolrDeletionPolicy.onInit: commits: num=1
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fe7089a lockFactory=org.apache.lucene.store.NativeFSLockFactory@26b7dac5),segFN=segments_1,generation=1}
[junit4:junit4] 2> 1581120 T4619 C3017 P55609 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 1
[junit4:junit4] 2> 1581120 T4619 C3017 P55609 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fe7089a lockFactory=org.apache.lucene.store.NativeFSLockFactory@26b7dac5),segFN=segments_1,generation=1}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@fe7089a lockFactory=org.apache.lucene.store.NativeFSLockFactory@26b7dac5),segFN=segments_2,generation=2}
[junit4:junit4] 2> 1581121 T4619 C3017 P55609 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 2
[junit4:junit4] 2> 1581121 T4619 C3017 P55609 oass.SolrIndexSearcher.<init> Opening Searcher@36d51f4a main
[junit4:junit4] 2> 1581122 T4619 C3017 P55609 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1581123 T4633 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@36d51f4a main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1581124 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 8
[junit4:junit4] 2> 1581135 T4659 C3016 P24236 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1581136 T4659 C3016 P24236 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2f5059b3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a1574c5),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@2f5059b3 lockFactory=org.apache.lucene.store.NativeFSLockFactory@7a1574c5),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1581137 T4659 C3016 P24236 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1581137 T4659 C3016 P24236 oass.SolrIndexSearcher.<init> Opening Searcher@63f9f403 main
[junit4:junit4] 2> 1581138 T4659 C3016 P24236 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1581139 T4667 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@63f9f403 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1581139 T4659 C3016 P24236 oasu.SolrCmdDistributor.distribCommit Distrib commit to:[StdNode: http://127.0.0.1:58798/ao_dxt/c/collection1/, StdNode: http://127.0.0.1:42801/ao_dxt/c/collection1/, StdNode: http://127.0.0.1:32595/ao_dxt/c/collection1/] params:commit_end_point=true&commit=true&softCommit=false&waitSearcher=true&expungeDeletes=false
[junit4:junit4] 2> 1581142 T4643 C3014 P58798 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1581143 T4643 C3014 P58798 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59bb6c6c lockFactory=org.apache.lucene.store.NativeFSLockFactory@41b8cbfe),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@59bb6c6c lockFactory=org.apache.lucene.store.NativeFSLockFactory@41b8cbfe),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1581143 T4643 C3014 P58798 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1581144 T4643 C3014 P58798 oass.SolrIndexSearcher.<init> Opening Searcher@6f0fdce7 main
[junit4:junit4] 2> 1581144 T4643 C3014 P58798 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1581145 T4651 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@6f0fdce7 main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1581146 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 4
[junit4:junit4] 2> C3015_STATE=coll:collection1 core:collection1 props:{shard=shard2, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:32595_ao_dxt%2Fc, base_url=http://127.0.0.1:32595/ao_dxt/c}
[junit4:junit4] 2> 1581150 T4688 C3015 P32595 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> C3013_STATE=coll:collection1 core:collection1 props:{shard=shard1, state=active, core=collection1, collection=collection1, node_name=127.0.0.1:42801_ao_dxt%2Fc, base_url=http://127.0.0.1:42801/ao_dxt/c}
[junit4:junit4] 2> 1581150 T4671 C3013 P42801 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4:junit4] 2> 1581150 T4688 C3015 P32595 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d2a7ade lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e4b0472),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d2a7ade lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e4b0472),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1581151 T4671 C3013 P42801 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1349bf37 lockFactory=org.apache.lucene.store.NativeFSLockFactory@44e00683),segFN=segments_2,generation=2}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1349bf37 lockFactory=org.apache.lucene.store.NativeFSLockFactory@44e00683),segFN=segments_3,generation=3}
[junit4:junit4] 2> 1581152 T4671 C3013 P42801 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1581151 T4688 C3015 P32595 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 3
[junit4:junit4] 2> 1581152 T4671 C3013 P42801 oass.SolrIndexSearcher.<init> Opening Searcher@503cb55d main
[junit4:junit4] 2> 1581153 T4688 C3015 P32595 oass.SolrIndexSearcher.<init> Opening Searcher@4089afaa main
[junit4:junit4] 2> 1581153 T4671 C3013 P42801 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1581154 T4688 C3015 P32595 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4:junit4] 2> 1581154 T4683 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@503cb55d main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1581154 T4700 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@4089afaa main{StandardDirectoryReader(segments_2:1:nrt)}
[junit4:junit4] 2> 1581155 T4671 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4] 2> 1581155 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={waitSearcher=true&commit=true&wt=javabin&expungeDeletes=false&commit_end_point=true&version=2&softCommit=false} {commit=} 0 5
[junit4:junit4] 2> 1581156 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={waitSearcher=true&commit=true&wt=javabin&version=2&softCommit=false} {commit=} 0 21
[junit4:junit4] 2> 1581157 T4607 oascc.ZkStateReader.updateClusterState Updating cloud state from ZooKeeper...
[junit4:junit4] 2> 1581160 T4644 C3014 P58798 oasc.SolrCore.execute [collection1] webapp=/ao_dxt/c path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 1581162 T4672 C3013 P42801 oasc.SolrCore.execute [collection1] webapp=/ao_dxt/c path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=1
[junit4:junit4] 2> 1581163 T4660 C3016 P24236 oasc.SolrCore.execute [collection1] webapp=/ao_dxt/c path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 1581165 T4689 C3015 P32595 oasc.SolrCore.execute [collection1] webapp=/ao_dxt/c path=/select params={tests=checkShardConsistency&q=*:*&distrib=false&wt=javabin&version=2&rows=0} hits=0 status=0 QTime=0
[junit4:junit4] 2> 1583170 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1436494399510937600)} 0 2
[junit4:junit4] 2> 1583177 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={update.distrib=FROMLEADER&_version_=-1436494399515131904&update.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1436494399515131904)} 0 2
[junit4:junit4] 2> 1583180 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={update.distrib=FROMLEADER&_version_=-1436494399519326208&update.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&wt=javabin&version=2} {deleteByQuery=*:* (-1436494399519326208)} 0 1
[junit4:junit4] 2> 1583181 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={update.distrib=TOLEADER&wt=javabin&version=2} {deleteByQuery=*:* (-1436494399519326208)} 0 6
[junit4:junit4] 2> 1583182 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {deleteByQuery=*:* (-1436494399515131904)} 0 10
[junit4:junit4] 2> 1583185 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[a!0 (1436494399527714816)]} 0 1
[junit4:junit4] 2> 1583192 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!0 (1436494399532957696)]} 0 0
[junit4:junit4] 2> 1583193 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[a!0 (1436494399532957696)]} 0 4
[junit4:junit4] 2> 1583194 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[a!0]} 0 7
[junit4:junit4] 2> 1583196 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[b!1 (1436494399540297728)]} 0 0
[junit4:junit4] 2> 1583202 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!1 (1436494399544492032)]} 0 0
[junit4:junit4] 2> 1583203 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[b!1 (1436494399544492032)]} 0 3
[junit4:junit4] 2> 1583206 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[c!2 (1436494399550783488)]} 0 0
[junit4:junit4] 2> 1583213 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!2 (1436494399556026368)]} 0 0
[junit4:junit4] 2> 1583214 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[c!2 (1436494399556026368)]} 0 3
[junit4:junit4] 2> 1583215 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[c!2]} 0 6
[junit4:junit4] 2> 1583218 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[d!3 (1436494399563366400)]} 0 0
[junit4:junit4] 2> 1583225 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!3 (1436494399568609280)]} 0 0
[junit4:junit4] 2> 1583226 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[d!3 (1436494399568609280)]} 0 3
[junit4:junit4] 2> 1583226 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[d!3]} 0 5
[junit4:junit4] 2> 1583229 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[e!4 (1436494399574900736)]} 0 0
[junit4:junit4] 2> 1583236 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!4 (1436494399580143616)]} 0 0
[junit4:junit4] 2> 1583237 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[e!4 (1436494399580143616)]} 0 3
[junit4:junit4] 2> 1583238 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[e!4]} 0 6
[junit4:junit4] 2> 1583240 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[f!5 (1436494399586435072)]} 0 0
[junit4:junit4] 2> 1583245 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!5 (1436494399589580800)]} 0 0
[junit4:junit4] 2> 1583246 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[f!5 (1436494399589580800)]} 0 3
[junit4:junit4] 2> 1583249 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[g!6 (1436494399595872256)]} 0 0
[junit4:junit4] 2> 1583256 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!6 (1436494399601115136)]} 0 0
[junit4:junit4] 2> 1583257 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[g!6 (1436494399601115136)]} 0 3
[junit4:junit4] 2> 1583258 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[g!6]} 0 6
[junit4:junit4] 2> 1583260 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[h!7 (1436494399607406592)]} 0 0
[junit4:junit4] 2> 1583266 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!7 (1436494399611600896)]} 0 0
[junit4:junit4] 2> 1583267 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[h!7 (1436494399611600896)]} 0 3
[junit4:junit4] 2> 1583270 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[i!8 (1436494399617892352)]} 0 0
[junit4:junit4] 2> 1583275 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!8 (1436494399621038080)]} 0 0
[junit4:junit4] 2> 1583276 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[i!8 (1436494399621038080)]} 0 3
[junit4:junit4] 2> 1583279 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[j!9 (1436494399627329536)]} 0 0
[junit4:junit4] 2> 1583286 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!9 (1436494399632572416)]} 0 0
[junit4:junit4] 2> 1583287 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[j!9 (1436494399632572416)]} 0 3
[junit4:junit4] 2> 1583288 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[j!9]} 0 6
[junit4:junit4] 2> 1583290 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[k!10 (1436494399638863872)]} 0 0
[junit4:junit4] 2> 1583295 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!10 (1436494399642009600)]} 0 0
[junit4:junit4] 2> 1583296 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[k!10 (1436494399642009600)]} 0 3
[junit4:junit4] 2> 1583300 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[l!11 (1436494399648301056)]} 0 1
[junit4:junit4] 2> 1583307 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!11 (1436494399653543936)]} 0 0
[junit4:junit4] 2> 1583308 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[l!11 (1436494399653543936)]} 0 4
[junit4:junit4] 2> 1583311 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[m!12 (1436494399660883968)]} 0 0
[junit4:junit4] 2> 1583320 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[m!12 (1436494399667175424)]} 0 0
[junit4:junit4] 2> 1583321 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[m!12 (1436494399667175424)]} 0 4
[junit4:junit4] 2> 1583322 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[m!12]} 0 8
[junit4:junit4] 2> 1583326 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[n!13 (1436494399675564032)]} 0 1
[junit4:junit4] 2> 1583334 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[n!13 (1436494399681855488)]} 0 0
[junit4:junit4] 2> 1583335 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[n!13 (1436494399681855488)]} 0 4
[junit4:junit4] 2> 1583336 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[n!13]} 0 7
[junit4:junit4] 2> 1583339 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[o!14 (1436494399690244096)]} 0 0
[junit4:junit4] 2> 1583348 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[o!14 (1436494399696535552)]} 0 0
[junit4:junit4] 2> 1583349 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[o!14 (1436494399696535552)]} 0 4
[junit4:junit4] 2> 1583350 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[o!14]} 0 8
[junit4:junit4] 2> 1583352 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[p!15 (1436494399703875584)]} 0 0
[junit4:junit4] 2> 1583358 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[p!15 (1436494399707021312)]} 0 0
[junit4:junit4] 2> 1583359 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[p!15 (1436494399707021312)]} 0 4
[junit4:junit4] 2> 1583362 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[q!16 (1436494399714361344)]} 0 0
[junit4:junit4] 2> 1583368 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[q!16 (1436494399717507072)]} 0 0
[junit4:junit4] 2> 1583369 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[q!16 (1436494399717507072)]} 0 4
[junit4:junit4] 2> 1583372 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[r!17 (1436494399724847104)]} 0 0
[junit4:junit4] 2> 1583379 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[r!17 (1436494399730089984)]} 0 0
[junit4:junit4] 2> 1583380 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[r!17 (1436494399730089984)]} 0 3
[junit4:junit4] 2> 1583381 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[r!17]} 0 6
[junit4:junit4] 2> 1583383 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[s!18 (1436494399736381440)]} 0 0
[junit4:junit4] 2> 1583389 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[s!18 (1436494399739527168)]} 0 0
[junit4:junit4] 2> 1583390 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[s!18 (1436494399739527168)]} 0 4
[junit4:junit4] 2> 1583393 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[t!19 (1436494399746867200)]} 0 0
[junit4:junit4] 2> 1583398 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[t!19 (1436494399750012928)]} 0 0
[junit4:junit4] 2> 1583399 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[t!19 (1436494399750012928)]} 0 3
[junit4:junit4] 2> 1583402 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[u!20 (1436494399756304384)]} 0 0
[junit4:junit4] 2> 1583407 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[u!20 (1436494399759450112)]} 0 0
[junit4:junit4] 2> 1583408 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[u!20 (1436494399759450112)]} 0 3
[junit4:junit4] 2> 1583413 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[v!21 (1436494399766790144)]} 0 1
[junit4:junit4] 2> 1583419 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[v!21 (1436494399772033024)]} 0 0
[junit4:junit4] 2> 1583420 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[v!21 (1436494399772033024)]} 0 3
[junit4:junit4] 2> 1583421 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[v!21]} 0 6
[junit4:junit4] 2> 1583423 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[w!22 (1436494399778324480)]} 0 0
[junit4:junit4] 2> 1583430 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[w!22 (1436494399783567360)]} 0 0
[junit4:junit4] 2> 1583431 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[w!22 (1436494399783567360)]} 0 3
[junit4:junit4] 2> 1583432 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[w!22]} 0 6
[junit4:junit4] 2> 1583435 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[x!23 (1436494399790907392)]} 0 0
[junit4:junit4] 2> 1583442 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[x!23 (1436494399796150272)]} 0 0
[junit4:junit4] 2> 1583443 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[x!23 (1436494399796150272)]} 0 3
[junit4:junit4] 2> 1583444 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[x!23]} 0 6
[junit4:junit4] 2> 1583446 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[y!24 (1436494399802441728)]} 0 0
[junit4:junit4] 2> 1583451 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[y!24 (1436494399805587456)]} 0 0
[junit4:junit4] 2> 1583452 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[y!24 (1436494399805587456)]} 0 3
[junit4:junit4] 2> 1583455 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[z!25 (1436494399811878912)]} 0 0
[junit4:junit4] 2> 1583460 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[z!25 (1436494399815024640)]} 0 0
[junit4:junit4] 2> 1583461 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[z!25 (1436494399815024640)]} 0 3
[junit4:junit4] 2> 1583464 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[a!26 (1436494399821316096)]} 0 0
[junit4:junit4] 2> 1583469 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!26 (1436494399824461824)]} 0 0
[junit4:junit4] 2> 1583470 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[a!26 (1436494399824461824)]} 0 3
[junit4:junit4] 2> 1583473 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[b!27 (1436494399830753280)]} 0 0
[junit4:junit4] 2> 1583480 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!27 (1436494399834947584)]} 0 0
[junit4:junit4] 2> 1583481 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[b!27 (1436494399834947584)]} 0 4
[junit4:junit4] 2> 1583484 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[c!28 (1436494399842287616)]} 0 0
[junit4:junit4] 2> 1583489 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!28 (1436494399845433344)]} 0 0
[junit4:junit4] 2> 1583490 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[c!28 (1436494399845433344)]} 0 3
[junit4:junit4] 2> 1583493 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[d!29 (1436494399851724800)]} 0 0
[junit4:junit4] 2> 1583500 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!29 (1436494399856967680)]} 0 0
[junit4:junit4] 2> 1583501 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[d!29 (1436494399856967680)]} 0 3
[junit4:junit4] 2> 1583502 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[d!29]} 0 6
[junit4:junit4] 2> 1583506 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[e!30 (1436494399865356288)]} 0 0
[junit4:junit4] 2> 1583513 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!30 (1436494399870599168)]} 0 0
[junit4:junit4] 2> 1583514 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[e!30 (1436494399870599168)]} 0 3
[junit4:junit4] 2> 1583515 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[e!30]} 0 6
[junit4:junit4] 2> 1583517 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[f!31 (1436494399876890624)]} 0 0
[junit4:junit4] 2> 1583524 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!31 (1436494399882133504)]} 0 0
[junit4:junit4] 2> 1583525 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[f!31 (1436494399882133504)]} 0 3
[junit4:junit4] 2> 1583526 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[f!31]} 0 6
[junit4:junit4] 2> 1583528 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[g!32 (1436494399888424960)]} 0 0
[junit4:junit4] 2> 1583533 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!32 (1436494399891570688)]} 0 0
[junit4:junit4] 2> 1583534 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[g!32 (1436494399891570688)]} 0 3
[junit4:junit4] 2> 1583537 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[h!33 (1436494399897862144)]} 0 0
[junit4:junit4] 2> 1583544 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!33 (1436494399903105024)]} 0 0
[junit4:junit4] 2> 1583545 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[h!33 (1436494399903105024)]} 0 3
[junit4:junit4] 2> 1583546 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[h!33]} 0 6
[junit4:junit4] 2> 1583548 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[i!34 (1436494399909396480)]} 0 0
[junit4:junit4] 2> 1583555 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!34 (1436494399914639360)]} 0 0
[junit4:junit4] 2> 1583556 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[i!34 (1436494399914639360)]} 0 3
[junit4:junit4] 2> 1583557 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[i!34]} 0 6
[junit4:junit4] 2> 1583559 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[j!35 (1436494399920930816)]} 0 0
[junit4:junit4] 2> 1583564 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!35 (1436494399924076544)]} 0 0
[junit4:junit4] 2> 1583565 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[j!35 (1436494399924076544)]} 0 3
[junit4:junit4] 2> 1583568 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[k!36 (1436494399930368000)]} 0 0
[junit4:junit4] 2> 1583575 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!36 (1436494399935610880)]} 0 0
[junit4:junit4] 2> 1583576 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[k!36 (1436494399935610880)]} 0 3
[junit4:junit4] 2> 1583577 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[k!36]} 0 6
[junit4:junit4] 2> 1583579 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[l!37 (1436494399941902336)]} 0 0
[junit4:junit4] 2> 1583585 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!37 (1436494399945048064)]} 0 0
[junit4:junit4] 2> 1583586 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[l!37 (1436494399945048064)]} 0 4
[junit4:junit4] 2> 1583589 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[m!38 (1436494399952388096)]} 0 0
[junit4:junit4] 2> 1583596 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[m!38 (1436494399955533824)]} 0 1
[junit4:junit4] 2> 1583597 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[m!38 (1436494399955533824)]} 0 5
[junit4:junit4] 2> 1583600 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[n!39 (1436494399962873856)]} 0 1
[junit4:junit4] 2> 1583607 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[n!39 (1436494399968116736)]} 0 0
[junit4:junit4] 2> 1583608 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[n!39 (1436494399968116736)]} 0 4
[junit4:junit4] 2> 1583609 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[n!39]} 0 7
[junit4:junit4] 2> 1583611 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[o!40 (1436494399975456768)]} 0 0
[junit4:junit4] 2> 1583616 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[o!40 (1436494399978602496)]} 0 0
[junit4:junit4] 2> 1583617 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[o!40 (1436494399978602496)]} 0 3
[junit4:junit4] 2> 1583620 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[p!41 (1436494399984893952)]} 0 0
[junit4:junit4] 2> 1583625 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[p!41 (1436494399988039680)]} 0 0
[junit4:junit4] 2> 1583626 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[p!41 (1436494399988039680)]} 0 3
[junit4:junit4] 2> 1583629 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[q!42 (1436494399994331136)]} 0 0
[junit4:junit4] 2> 1583636 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[q!42 (1436494399999574016)]} 0 0
[junit4:junit4] 2> 1583637 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[q!42 (1436494399999574016)]} 0 3
[junit4:junit4] 2> 1583638 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[q!42]} 0 6
[junit4:junit4] 2> 1583641 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[r!43 (1436494400006914048)]} 0 0
[junit4:junit4] 2> 1583649 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[r!43 (1436494400012156928)]} 0 0
[junit4:junit4] 2> 1583650 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[r!43 (1436494400012156928)]} 0 4
[junit4:junit4] 2> 1583651 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[r!43]} 0 7
[junit4:junit4] 2> 1583653 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[s!44 (1436494400019496960)]} 0 0
[junit4:junit4] 2> 1583658 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[s!44 (1436494400022642688)]} 0 0
[junit4:junit4] 2> 1583659 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[s!44 (1436494400022642688)]} 0 3
[junit4:junit4] 2> 1583662 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[t!45 (1436494400028934144)]} 0 0
[junit4:junit4] 2> 1583670 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[t!45 (1436494400035225600)]} 0 0
[junit4:junit4] 2> 1583671 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[t!45 (1436494400035225600)]} 0 3
[junit4:junit4] 2> 1583672 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[t!45]} 0 6
[junit4:junit4] 2> 1583674 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[u!46 (1436494400041517056)]} 0 0
[junit4:junit4] 2> 1583681 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[u!46 (1436494400046759936)]} 0 0
[junit4:junit4] 2> 1583682 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[u!46 (1436494400046759936)]} 0 3
[junit4:junit4] 2> 1583683 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[u!46]} 0 6
[junit4:junit4] 2> 1583687 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[v!47 (1436494400054099968)]} 0 1
[junit4:junit4] 2> 1583691 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[v!47 (1436494400057245696)]} 0 0
[junit4:junit4] 2> 1583692 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[v!47 (1436494400057245696)]} 0 3
[junit4:junit4] 2> 1583696 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[w!48 (1436494400063537152)]} 0 1
[junit4:junit4] 2> 1583701 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[w!48 (1436494400066682880)]} 0 0
[junit4:junit4] 2> 1583702 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[w!48 (1436494400066682880)]} 0 4
[junit4:junit4] 2> 1583705 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[x!49 (1436494400074022912)]} 0 0
[junit4:junit4] 2> 1583713 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[x!49 (1436494400079265792)]} 0 0
[junit4:junit4] 2> 1583714 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[x!49 (1436494400079265792)]} 0 4
[junit4:junit4] 2> 1583715 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[x!49]} 0 7
[junit4:junit4] 2> 1583717 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[y!50 (1436494400086605824)]} 0 0
[junit4:junit4] 2> 1583724 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[y!50 (1436494400091848704)]} 0 0
[junit4:junit4] 2> 1583725 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[y!50 (1436494400091848704)]} 0 3
[junit4:junit4] 2> 1583726 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[y!50]} 0 6
[junit4:junit4] 2> 1583728 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[z!51 (1436494400098140160)]} 0 0
[junit4:junit4] 2> 1583735 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[z!51 (1436494400103383040)]} 0 0
[junit4:junit4] 2> 1583736 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[z!51 (1436494400103383040)]} 0 3
[junit4:junit4] 2> 1583736 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[z!51]} 0 5
[junit4:junit4] 2> 1583739 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[a!52 (1436494400109674496)]} 0 0
[junit4:junit4] 2> 1583744 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[a!52 (1436494400112820224)]} 0 0
[junit4:junit4] 2> 1583745 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[a!52 (1436494400112820224)]} 0 3
[junit4:junit4] 2> 1583748 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[b!53 (1436494400119111680)]} 0 0
[junit4:junit4] 2> 1583754 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[b!53 (1436494400122257408)]} 0 0
[junit4:junit4] 2> 1583755 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[b!53 (1436494400122257408)]} 0 4
[junit4:junit4] 2> 1583759 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[c!54 (1436494400130646016)]} 0 0
[junit4:junit4] 2> 1583764 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[c!54 (1436494400133791744)]} 0 0
[junit4:junit4] 2> 1583765 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[c!54 (1436494400133791744)]} 0 3
[junit4:junit4] 2> 1583768 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[d!55 (1436494400140083200)]} 0 0
[junit4:junit4] 2> 1583775 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[d!55 (1436494400145326080)]} 0 0
[junit4:junit4] 2> 1583776 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[d!55 (1436494400145326080)]} 0 3
[junit4:junit4] 2> 1583776 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[d!55]} 0 5
[junit4:junit4] 2> 1583779 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[e!56 (1436494400151617536)]} 0 0
[junit4:junit4] 2> 1583786 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[e!56 (1436494400156860416)]} 0 0
[junit4:junit4] 2> 1583787 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[e!56 (1436494400156860416)]} 0 3
[junit4:junit4] 2> 1583788 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[e!56]} 0 6
[junit4:junit4] 2> 1583790 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[f!57 (1436494400163151872)]} 0 0
[junit4:junit4] 2> 1583798 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[f!57 (1436494400169443328)]} 0 0
[junit4:junit4] 2> 1583799 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[f!57 (1436494400169443328)]} 0 3
[junit4:junit4] 2> 1583800 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[f!57]} 0 7
[junit4:junit4] 2> 1583802 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[g!58 (1436494400175734784)]} 0 0
[junit4:junit4] 2> 1583809 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[g!58 (1436494400180977664)]} 0 0
[junit4:junit4] 2> 1583810 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[g!58 (1436494400180977664)]} 0 3
[junit4:junit4] 2> 1583810 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[g!58]} 0 5
[junit4:junit4] 2> 1583813 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[h!59 (1436494400187269120)]} 0 0
[junit4:junit4] 2> 1583820 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[h!59 (1436494400192512000)]} 0 0
[junit4:junit4] 2> 1583821 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[h!59 (1436494400192512000)]} 0 3
[junit4:junit4] 2> 1583821 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[h!59]} 0 5
[junit4:junit4] 2> 1583824 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[i!60 (1436494400198803456)]} 0 0
[junit4:junit4] 2> 1583832 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[i!60 (1436494400204046336)]} 0 0
[junit4:junit4] 2> 1583833 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[i!60 (1436494400204046336)]} 0 4
[junit4:junit4] 2> 1583834 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[i!60]} 0 7
[junit4:junit4] 2> 1583836 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[j!61 (1436494400211386368)]} 0 0
[junit4:junit4] 2> 1583841 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[j!61 (1436494400214532096)]} 0 0
[junit4:junit4] 2> 1583842 T4645 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[j!61 (1436494400214532096)]} 0 3
[junit4:junit4] 2> 1583844 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[k!62 (1436494400219774976)]} 0 0
[junit4:junit4] 2> 1583851 T4673 C3013 P42801 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:58798/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[k!62 (1436494400225017856)]} 0 0
[junit4:junit4] 2> 1583852 T4643 C3014 P58798 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=TOLEADER&wt=javabin&version=2} {add=[k!62 (1436494400225017856)]} 0 3
[junit4:junit4] 2> 1583852 T4659 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[k!62]} 0 5
[junit4:junit4] 2> 1583855 T4619 C3017 P55609 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={wt=javabin&version=2} {add=[l!63 (1436494400231309312)]} 0 0
[junit4:junit4] 2> 1583862 T4688 C3015 P32595 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dxt/c path=/update params={distrib.from=http://127.0.0.1:24236/ao_dxt/c/collection1/&update.distrib=FROMLEADER&wt=javabin&version=2} {add=[l!63 (1436494400236552192)]} 0 0
[junit4:junit4] 2> 1583863 T4661 C3016 P24236 oasup.LogUpdateProcessor.finish [collection1] webapp=/ao_dx
[...truncated too long message...]
. (live nodes size: 4)
[junit4:junit4] 2> 1622492 T4681 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1623627 T4698 oasu.PeerSync.handleResponse WARN PeerSync: core=collection1 url=http://127.0.0.1:32595/ao_dxt/c couldn't connect to http://127.0.0.1:24236/ao_dxt/c/collection1/, counting as success
[junit4:junit4] 2> 1623627 T4698 oasu.PeerSync.sync PeerSync: core=collection1 url=http://127.0.0.1:32595/ao_dxt/c DONE. sync succeeded
[junit4:junit4] 2> 1623627 T4698 oasc.SyncStrategy.syncReplicas We have been closed, won't attempt to sync replicas back to leader
[junit4:junit4] 2> 1623628 T4698 oasc.ShardLeaderElectionContext.rejoinLeaderElection Not rejoining election because CoreContainer is shutdown
[junit4:junit4] 2> 1623628 T4698 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@485b806a
[junit4:junit4] 2> 1623634 T4698 oasu.DirectUpdateHandler2.close closing DirectUpdateHandler2{commits=2,autocommits=0,soft autocommits=0,optimizes=0,rollbacks=0,expungeDeletes=0,docsPending=10,adds=10,deletesById=0,deletesByQuery=0,errors=0,cumulative_adds=52,cumulative_deletesById=0,cumulative_deletesByQuery=1,cumulative_errors=0}
[junit4:junit4] 2> 1623635 T4698 oasu.SolrCoreState.decrefSolrCoreState Closing SolrCoreState
[junit4:junit4] 2> 1623635 T4698 oasu.DefaultSolrCoreState.closeIndexWriter SolrCoreState ref count has reached 0 - closing IndexWriter
[junit4:junit4] 2> 1623635 T4698 oasu.DefaultSolrCoreState.closeIndexWriter closing IndexWriter with IndexWriterCloser
[junit4:junit4] 2> 1623636 T4698 C3015 P32595 oasc.SolrDeletionPolicy.onCommit SolrDeletionPolicy.onCommit: commits: num=2
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d2a7ade lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e4b0472),segFN=segments_4,generation=4}
[junit4:junit4] 2> commit{dir=MockDirWrapper(org.apache.lucene.store.RAMDirectory@1d2a7ade lockFactory=org.apache.lucene.store.NativeFSLockFactory@6e4b0472),segFN=segments_5,generation=5}
[junit4:junit4] 2> 1623637 T4698 C3015 P32595 oasc.SolrDeletionPolicy.updateCommits newest commit generation = 5
[junit4:junit4] 2> 1623639 T4698 oasc.SolrCore.closeSearcher [collection1] Closing main searcher on request.
[junit4:junit4] 2> 1623639 T4698 oasc.CachingDirectoryFactory.close Closing MockDirectoryFactory - 2 directories currently being tracked
[junit4:junit4] 2> 1623640 T4698 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/index [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/index;done=false>>]
[junit4:junit4] 2> 1623640 T4698 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4/index
[junit4:junit4] 2> 1623640 T4698 oasc.CachingDirectoryFactory.closeCacheValue looking to close ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4 [CachedDir<<refCount=0;path=./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4;done=false>>]
[junit4:junit4] 2> 1623640 T4698 oasc.CachingDirectoryFactory.close Closing directory: ./org.apache.solr.cloud.ShardSplitTest-1369947787048/jetty4
[junit4:junit4] 2> 1623640 T4698 oascc.ZkStateReader$2.process A cluster state change: WatchedEvent state:SyncConnected type:NodeChildrenChanged path:/live_nodes, has occurred - updating... (live nodes size: 3)
[junit4:junit4] 2> 1623641 T4698 oascc.ZkStateReader$2.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1623641 T4698 oascc.ZkStateReader$3.process WARN ZooKeeper watch triggered, but Solr cannot talk to ZK
[junit4:junit4] 2> 1623641 T4698 oasc.LeaderElector$1.process WARN org.apache.zookeeper.KeeperException$SessionExpiredException: KeeperErrorCode = Session expired for /overseer_elect/election
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:127)
[junit4:junit4] 2> at org.apache.zookeeper.KeeperException.create(KeeperException.java:51)
[junit4:junit4] 2> at org.apache.zookeeper.ZooKeeper.getChildren(ZooKeeper.java:1468)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:235)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$6.execute(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:65)
[junit4:junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.getChildren(SolrZkClient.java:232)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.checkIfIamLeader(LeaderElector.java:84)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector.access$000(LeaderElector.java:55)
[junit4:junit4] 2> at org.apache.solr.cloud.LeaderElector$1.process(LeaderElector.java:129)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.processEvent(ClientCnxn.java:519)
[junit4:junit4] 2> at org.apache.zookeeper.ClientCnxn$EventThread.run(ClientCnxn.java:495)
[junit4:junit4] 2>
[junit4:junit4] 2> NOTE: test params are: codec=Appending, sim=DefaultSimilarity, locale=es_NI, timezone=Asia/Amman
[junit4:junit4] 2> NOTE: FreeBSD 9.1-RELEASE-p3 amd64/Sun Microsystems Inc. 1.6.0_32 (64-bit)/cpus=16,threads=3,free=209699328,total=434110464
[junit4:junit4] 2> NOTE: All tests run in this JVM: [TestStressRecovery, TestReversedWildcardFilterFactory, TestSolrIndexConfig, AliasIntegrationTest, LegacyHTMLStripCharFilterTest, SchemaVersionSpecificBehaviorTest, PreAnalyzedFieldTest, SuggesterFSTTest, TestFunctionQuery, UpdateRequestProcessorFactoryTest, TestPropInjectDefaults, TestSolrQueryParser, TestManagedSchemaFieldResource, SimpleFacetsTest, TermVectorComponentTest, TestSort, TestCloudManagedSchema, QueryEqualityTest, DistributedTermsComponentTest, TestConfig, TestRandomDVFaceting, OverseerCollectionProcessorTest, SpellingQueryConverterTest, RAMDirectoryFactoryTest, SearchHandlerTest, SynonymTokenizerTest, SolrInfoMBeanTest, TestFaceting, TestFastLRUCache, BadCopyFieldTest, SliceStateTest, LeaderElectionTest, FastVectorHighlighterTest, MoreLikeThisHandlerTest, TestSchemaVersionResource, SpatialFilterTest, DirectUpdateHandlerOptimizeTest, PeerSyncTest, DistributedSpellCheckComponentTest, FieldMutatingUpdateProcessorTest, BadComponentTest, SyncSliceTest, BasicDistributedZkTest, TestSolrCoreProperties, LukeRequestHandlerTest, TestDynamicFieldResource, ScriptEngineTest, BinaryUpdateRequestHandlerTest, TestTrie, AnalysisAfterCoreReloadTest, TestRealTimeGet, AutoCommitTest, ExternalFileFieldSortTest, TestFuzzyAnalyzedSuggestions, TestManagedSchema, TestReplicationHandler, BasicFunctionalityTest, TestPerFieldSimilarity, TestSurroundQueryParser, TestSolrDeletionPolicy1, PrimUtilsTest, DocValuesTest, CircularListTest, PluginInfoTest, ZkControllerTest, TestWriterPerf, ResponseLogComponentTest, TestPluginEnable, TestDocSet, SystemInfoHandlerTest, CSVRequestHandlerTest, UnloadDistributedZkTest, OpenCloseCoreStressTest, ShardRoutingTest, RecoveryZkTest, FullSolrCloudDistribCmdsTest, ClusterStateUpdateTest, TestZkChroot, TestDistributedGrouping, TestHashPartitioner, TestMultiCoreConfBootstrap, TestReload, TestStressVersions, HardAutoCommitTest, TestCoreContainer, SolrCoreTest, SpellCheckComponentTest, SolrCmdDistributorTest, QueryElevationComponentTest, TestLazyCores, DirectUpdateHandlerTest, TestBadConfig, ShowFileRequestHandlerTest, CurrencyFieldOpenExchangeTest, DistributedQueryElevationComponentTest, SolrIndexSplitterTest, SimplePostToolTest, TestExtendedDismaxParser, SuggesterTSTTest, TestStressLucene, SuggesterWFSTTest, WordBreakSolrSpellCheckerTest, TestPseudoReturnFields, TestRemoteStreaming, CacheHeaderTest, TestQueryUtils, PrimitiveFieldTypeTest, FileBasedSpellCheckerTest, XmlUpdateRequestHandlerTest, TestValueSourceCache, RequiredFieldsTest, LoggingHandlerTest, IndexSchemaTest, ReturnFieldsTest, JSONWriterTest, MBeansHandlerTest, JsonLoaderTest, PingRequestHandlerTest, HighlighterConfigTest, TestQuerySenderListener, UpdateParamsTest, TestQuerySenderNoQuery, SolrIndexConfigTest, TestSolrDeletionPolicy2, TestSearchPerf, MinimalSchemaTest, NotRequiredUniqueKeyTest, SpellPossibilityIteratorTest, TestCodecSupport, EchoParamsTest, TestDFRSimilarityFactory, TestLMJelinekMercerSimilarityFactory, TestBM25SimilarityFactory, TestJmxMonitoredMap, ResourceLoaderTest, URLClassifyProcessorTest, ChaosMonkeyNothingIsSafeTest, DOMUtilTest, TestLRUCache, ZkNodePropsTest, UUIDFieldTest, SolrTestCaseJ4Test, ShardSplitTest]
[junit4:junit4] Completed on J0 in 68.43s, 1 test, 1 error <<< FAILURES!
[...truncated 22 lines...]
BUILD FAILED
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:386: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:366: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/build.xml:39: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/build.xml:181: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/solr/common-build.xml:437: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:1243: The following error occurred while executing this line:
/usr/home/hudson/hudson-slave/workspace/Lucene-Solr-Tests-4.x-Java6/lucene/common-build.xml:887: There were test failures: 296 suites, 1235 tests, 1 error, 13 ignored (7 assumptions)
Total time: 47 minutes 34 seconds
Build step 'Invoke Ant' marked build as failure
Archiving artifacts
Recording test results
Email was triggered for: Failure
Sending email for trigger: Failure