[JENKINS] Lucene-Solr-Tests-master - Build # 1823 - Still Unstable

[Apache Jenkins Server]

Build: https://builds.apache.org/job/Lucene-Solr-Tests-master/1823/

1 tests failed.
FAILED:  org.apache.solr.TestDistributedSearch.test

Error Message:
Expected to find shardAddress in the up shard info: 
{error=org.apache.solr.client.solrj.SolrServerException: Time allowed to handle 
this request exceeded,trace=org.apache.solr.client.solrj.SolrServerException: 
Time allowed to handle this request exceeded  at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:428)
  at 
org.apache.solr.handler.component.HttpShardHandlerFactory.makeLoadBalancedRequest(HttpShardHandlerFactory.java:255)
  at 
org.apache.solr.handler.component.HttpShardHandler.lambda$submit$0(HttpShardHandler.java:166)
  at java.util.concurrent.FutureTask.run(FutureTask.java:266)  at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)  at 
java.util.concurrent.FutureTask.run(FutureTask.java:266)  at 
com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
  at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
  at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) 
 at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) 
 at java.lang.Thread.run(Thread.java:745) ,time=1}

Stack Trace:
java.lang.AssertionError: Expected to find shardAddress in the up shard info: 
{error=org.apache.solr.client.solrj.SolrServerException: Time allowed to handle 
this request exceeded,trace=org.apache.solr.client.solrj.SolrServerException: 
Time allowed to handle this request exceeded
        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:428)
        at 
org.apache.solr.handler.component.HttpShardHandlerFactory.makeLoadBalancedRequest(HttpShardHandlerFactory.java:255)
        at 
org.apache.solr.handler.component.HttpShardHandler.lambda$submit$0(HttpShardHandler.java:166)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at 
com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)
,time=1}
        at 
__randomizedtesting.SeedInfo.seed([45DF33F73737834A:CD8B0C2D99CBEEB2]:0)
        at org.junit.Assert.fail(Assert.java:93)
        at org.junit.Assert.assertTrue(Assert.java:43)
        at 
org.apache.solr.TestDistributedSearch.comparePartialResponses(TestDistributedSearch.java:1186)
        at 
org.apache.solr.TestDistributedSearch.queryPartialResults(TestDistributedSearch.java:1127)
        at 
org.apache.solr.TestDistributedSearch.test(TestDistributedSearch.java:987)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at 
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at 
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsRepeatStatement.callStatement(BaseDistributedSearchTestCase.java:1011)
        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at java.lang.Thread.run(Thread.java:745)




Build Log:
[...truncated 11538 lines...]
   [junit4] Suite: org.apache.solr.TestDistributedSearch
   [junit4]   2> Creating dataDir: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_45DF33F73737834A-001/init-core-data-001
   [junit4]   2> 418061 WARN  
(SUITE-TestDistributedSearch-seed#[45DF33F73737834A]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
   [junit4]   2> 418062 INFO  
(SUITE-TestDistributedSearch-seed#[45DF33F73737834A]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using TrieFields
   [junit4]   2> 418063 INFO  
(SUITE-TestDistributedSearch-seed#[45DF33F73737834A]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: 
@org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=https://issues.apache.org/jira/browse/SOLR-9061)
   [junit4]   2> 418063 INFO  
(SUITE-TestDistributedSearch-seed#[45DF33F73737834A]-worker) [    ] 
o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /nqz/zp
   [junit4]   2> 418202 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_45DF33F73737834A-001/tempDir-001/control/cores/collection1
   [junit4]   2> 418205 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] o.e.j.s.Server 
jetty-9.3.14.v20161028
   [junit4]   2> 418206 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@7dce4253{/nqz/zp,null,AVAILABLE}
   [junit4]   2> 418211 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@36b5a042{HTTP/1.1,[http/1.1]}{127.0.0.1:39240}
   [junit4]   2> 418211 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] o.e.j.s.Server 
Started @421066ms
   [junit4]   2> 418211 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/nqz/zp, 
hostPort=39240, 
coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_45DF33F73737834A-001/tempDir-001/control/cores}
   [junit4]   2> 418211 ERROR 
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 418211 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.0.0
   [junit4]   2> 418212 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in standalone mode on 
port null
   [junit4]   2> 418212 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 418212 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-05-09T07:09:12.206Z
   [junit4]   2> 418212 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_45DF33F73737834A-001/tempDir-001/control/solr.xml
   [junit4]   2> 418218 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.SolrXmlConfig MBean server found: 
com.sun.jmx.mbeanserver.JmxMBeanServer@579d4f4, but no JMX reporters were 
configured - adding default JMX reporter.
   [junit4]   2> 418263 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') 
enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@579d4f4
   [junit4]   2> 418269 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') 
enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@579d4f4
   [junit4]   2> 418270 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@579d4f4
   [junit4]   2> 418272 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_45DF33F73737834A-001/tempDir-001/control/cores
   [junit4]   2> 418272 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 418273 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, 
from paths: 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1/lib,
 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 418309 WARN  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is 
deprecated, use <mergePolicyFactory> instead.
   [junit4]   2> 418311 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 418352 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 418483 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 418490 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using 
configuration from configset 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1,
 trusted=true
   [junit4]   2> 418491 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@579d4f4
   [junit4]   2> 418491 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 418491 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_45DF33F73737834A-001/tempDir-001/control/cores/collection1/data/]
   [junit4]   2> 418493 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: 
minMergeSize=0, mergeFactor=10, maxMergeSize=756456830, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.1]
   [junit4]   2> 418581 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 418581 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= 
defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 
numVersionBuckets=65536
   [junit4]   2> 418583 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 418583 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 418584 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: 
minMergeSize=1677721, mergeFactor=13, maxMergeSize=2147483648, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.8885865587394466]
   [junit4]   2> 418584 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.s.SolrIndexSearcher Opening 
[Searcher@645bf134[collection1] main]
   [junit4]   2> 418585 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 418599 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.s.DirectSolrSpellChecker init: 
{name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 418639 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 418639 INFO  
(searcherExecutor-2095-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 418639 INFO  (coreLoadExecutor-2094-thread-1) [    
x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent 
updates, using new clock 1566901537480900608
   [junit4]   2> 418640 INFO  
(searcherExecutor-2095-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 418640 INFO  
(searcherExecutor-2095-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 418640 INFO  
(searcherExecutor-2095-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: 
multipleFields
   [junit4]   2> 418640 INFO  
(searcherExecutor-2095-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 418641 INFO  
(searcherExecutor-2095-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 418641 INFO  
(searcherExecutor-2095-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 418641 INFO  
(searcherExecutor-2095-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 418641 INFO  
(searcherExecutor-2095-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 418643 INFO  
(searcherExecutor-2095-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@645bf134[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 418929 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_45DF33F73737834A-001/tempDir-001/shard0/cores/collection1
   [junit4]   2> 418931 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] o.e.j.s.Server 
jetty-9.3.14.v20161028
   [junit4]   2> 418933 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@485fd2be{/nqz/zp,null,AVAILABLE}
   [junit4]   2> 418933 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@7c2a3a25{HTTP/1.1,[http/1.1]}{127.0.0.1:34476}
   [junit4]   2> 418934 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] o.e.j.s.Server 
Started @421789ms
   [junit4]   2> 418934 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/nqz/zp, 
hostPort=34476, 
coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_45DF33F73737834A-001/tempDir-001/shard0/cores}
   [junit4]   2> 418934 ERROR 
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 418934 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr? version 
7.0.0
   [junit4]   2> 418934 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in standalone mode on 
port null
   [junit4]   2> 418935 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 418935 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2017-05-09T07:09:12.929Z
   [junit4]   2> 418935 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_45DF33F73737834A-001/tempDir-001/shard0/solr.xml
   [junit4]   2> 418941 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.SolrXmlConfig MBean server found: 
com.sun.jmx.mbeanserver.JmxMBeanServer@579d4f4, but no JMX reporters were 
configured - adding default JMX reporter.
   [junit4]   2> 418983 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') 
enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@579d4f4
   [junit4]   2> 418990 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') 
enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@579d4f4
   [junit4]   2> 418990 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@579d4f4
   [junit4]   2> 418993 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_45DF33F73737834A-001/tempDir-001/shard0/cores
   [junit4]   2> 418993 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 418994 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, 
from paths: 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1/lib,
 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 419030 WARN  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.c.Config Beginning with Solr 5.5, <mergePolicy> is 
deprecated, use <mergePolicyFactory> instead.
   [junit4]   2> 419032 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 419061 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 419200 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 419207 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using 
configuration from configset 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1,
 trusted=true
   [junit4]   2> 419207 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@579d4f4
   [junit4]   2> 419208 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 419208 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/core/src/test-files/solr/collection1],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_45DF33F73737834A-001/tempDir-001/shard0/cores/collection1/data/]
   [junit4]   2> 419210 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.AlcoholicMergePolicy: [AlcoholicMergePolicy: 
minMergeSize=0, mergeFactor=10, maxMergeSize=756456830, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.1]
   [junit4]   2> 419290 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 419290 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= 
defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 
numVersionBuckets=65536
   [junit4]   2> 419292 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 419292 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 419297 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy: 
minMergeSize=1677721, mergeFactor=13, maxMergeSize=2147483648, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.8885865587394466]
   [junit4]   2> 419304 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.s.SolrIndexSearcher Opening 
[Searcher@1784cab2[collection1] main]
   [junit4]   2> 419306 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 419315 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.s.DirectSolrSpellChecker init: 
{name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 419347 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 419347 INFO  
(searcherExecutor-2106-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 419347 INFO  (coreLoadExecutor-2105-thread-1) [    
x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent 
updates, using new clock 1566901538223292416
   [junit4]   2> 419348 INFO  
(searcherExecutor-2106-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 419348 INFO  
(searcherExecutor-2106-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 419348 INFO  
(searcherExecutor-2106-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: 
multipleFields
   [junit4]   2> 419348 INFO  
(searcherExecutor-2106-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 419349 INFO  
(searcherExecutor-2106-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 419349 INFO  
(searcherExecutor-2106-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 419349 INFO  
(searcherExecutor-2106-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 419349 INFO  
(searcherExecutor-2106-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 419351 INFO  
(searcherExecutor-2106-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@1784cab2[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 419523 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting test
   [junit4]   2> 419528 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{deleteByQuery=*:* (-1566901538410987520)} 0 2
   [junit4]   2> 419532 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{deleteByQuery=*:* (-1566901538415181824)} 0 2
   [junit4]   2> 419537 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[1 (1566901538418327552)]} 0 3
   [junit4]   2> 419541 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[1 (1566901538423570432)]} 0 2
   [junit4]   2> 419543 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[2 (1566901538427764736)]} 0 1
   [junit4]   2> 419545 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[2 (1566901538429861888)]} 0 1
   [junit4]   2> 419547 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[3 (1566901538431959040)]} 0 0
   [junit4]   2> 419548 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[3 (1566901538434056192)]} 0 0
   [junit4]   2> 419550 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[4 (1566901538435104768)]} 0 0
   [junit4]   2> 419552 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[4 (1566901538437201920)]} 0 0
   [junit4]   2> 419553 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[5 (1566901538438250496)]} 0 0
   [junit4]   2> 419554 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[5 (1566901538440347648)]} 0 0
   [junit4]   2> 419556 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[6 (1566901538441396224)]} 0 0
   [junit4]   2> 419557 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[6 (1566901538442444800)]} 0 0
   [junit4]   2> 419559 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[7 (1566901538444541952)]} 0 1
   [junit4]   2> 419561 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[7 (1566901538446639104)]} 0 0
   [junit4]   2> 419562 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[8 (1566901538447687680)]} 0 0
   [junit4]   2> 419564 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[8 (1566901538449784832)]} 0 0
   [junit4]   2> 419565 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[9 (1566901538450833408)]} 0 0
   [junit4]   2> 419566 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[9 (1566901538452930560)]} 0 0
   [junit4]   2> 419567 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 419567 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@302a2a7 commitCommandVersion:0
   [junit4]   2> 419580 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@2a9e5e6[collection1] main]
   [junit4]   2> 419581 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 419583 INFO  
(searcherExecutor-2095-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@2a9e5e6[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C9)))}
   [junit4]   2> 419583 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 15
   [junit4]   2> 419584 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 419584 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@510c3361 commitCommandVersion:0
   [junit4]   2> 419596 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@3a8c2047[collection1] main]
   [junit4]   2> 419596 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 419598 INFO  
(searcherExecutor-2106-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@3a8c2047[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C9)))}
   [junit4]   2> 419598 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 14
   [junit4]   2> 419603 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[10 (1566901538488582144)]} 0 3
   [junit4]   2> 419611 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[10 (1566901538492776448)]} 0 7
   [junit4]   2> 419613 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[11 (1566901538501165056)]} 0 1
   [junit4]   2> 419621 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[11 (1566901538503262208)]} 0 7
   [junit4]   2> 419623 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[12 (1566901538511650816)]} 0 1
   [junit4]   2> 419625 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[12 (1566901538513747968)]} 0 0
   [junit4]   2> 419626 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[13 (1566901538515845120)]} 0 0
   [junit4]   2> 419628 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[13 (1566901538516893696)]} 0 0
   [junit4]   2> 419631 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[1001 (1566901538518990848)]} 0 2
   [junit4]   2> 419633 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[1001 (1566901538522136576)]} 0 1
   [junit4]   2> 419635 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[14 (1566901538524233728)]} 0 0
   [junit4]   2> 419636 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[14 (1566901538525282304)]} 0 0
   [junit4]   2> 419637 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[15 (1566901538527379456)]} 0 0
   [junit4]   2> 419639 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[15 (1566901538528428032)]} 0 0
   [junit4]   2> 419640 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[16 (1566901538529476608)]} 0 0
   [junit4]   2> 419641 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[16 (1566901538531573760)]} 0 0
   [junit4]   2> 419643 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[17 (1566901538532622336)]} 0 0
   [junit4]   2> 419644 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[17 (1566901538533670912)]} 0 0
   [junit4]   2> 419645 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[100 (1566901538535768064)]} 0 0
   [junit4]   2> 419646 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[100 (1566901538536816640)]} 0 0
   [junit4]   2> 419647 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[101 (1566901538537865216)]} 0 0
   [junit4]   2> 419648 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[101 (1566901538538913792)]} 0 0
   [junit4]   2> 419650 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[102 (1566901538539962368)]} 0 0
   [junit4]   2> 419651 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[102 (1566901538541010944)]} 0 0
   [junit4]   2> 419652 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[103 (1566901538542059520)]} 0 0
   [junit4]   2> 419653 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[103 (1566901538543108096)]} 0 0
   [junit4]   2> 419654 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[104 (1566901538545205248)]} 0 0
   [junit4]   2> 419655 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[104 (1566901538546253824)]} 0 0
   [junit4]   2> 419656 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[105 (1566901538547302400)]} 0 0
   [junit4]   2> 419657 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[105 (1566901538548350976)]} 0 0
   [junit4]   2> 419659 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[106 (1566901538549399552)]} 0 0
   [junit4]   2> 419660 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[106 (1566901538550448128)]} 0 0
   [junit4]   2> 419661 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[107 (1566901538551496704)]} 0 0
   [junit4]   2> 419662 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[107 (1566901538552545280)]} 0 0
   [junit4]   2> 419663 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[108 (1566901538553593856)]} 0 0
   [junit4]   2> 419664 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[108 (1566901538555691008)]} 0 0
   [junit4]   2> 419665 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[109 (1566901538556739584)]} 0 0
   [junit4]   2> 419666 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[109 (1566901538557788160)]} 0 0
   [junit4]   2> 419667 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[110 (1566901538558836736)]} 0 0
   [junit4]   2> 419668 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[110 (1566901538559885312)]} 0 0
   [junit4]   2> 419670 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[111 (1566901538560933888)]} 0 0
   [junit4]   2> 419672 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[111 (1566901538563031040)]} 0 1
   [junit4]   2> 419673 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[112 (1566901538564079616)]} 0 0
   [junit4]   2> 419678 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[112 (1566901538569322496)]} 0 0
   [junit4]   2> 419679 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[113 (1566901538571419648)]} 0 0
   [junit4]   2> 419680 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[113 (1566901538572468224)]} 0 0
   [junit4]   2> 419682 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[114 (1566901538573516800)]} 0 0
   [junit4]   2> 419684 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[114 (1566901538575613952)]} 0 0
   [junit4]   2> 419685 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[115 (1566901538577711104)]} 0 0
   [junit4]   2> 419686 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[115 (1566901538578759680)]} 0 0
   [junit4]   2> 419688 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[116 (1566901538579808256)]} 0 0
   [junit4]   2> 419689 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[116 (1566901538581905408)]} 0 0
   [junit4]   2> 419691 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[117 (1566901538582953984)]} 0 0
   [junit4]   2> 419693 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[117 (1566901538585051136)]} 0 1
   [junit4]   2> 419695 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[118 (1566901538587148288)]} 0 0
   [junit4]   2> 419696 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[118 (1566901538589245440)]} 0 0
   [junit4]   2> 419698 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[119 (1566901538590294016)]} 0 0
   [junit4]   2> 419699 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[119 (1566901538591342592)]} 0 0
   [junit4]   2> 419700 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[120 (1566901538592391168)]} 0 0
   [junit4]   2> 419701 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[120 (1566901538594488320)]} 0 0
   [junit4]   2> 419702 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[121 (1566901538595536896)]} 0 0
   [junit4]   2> 419703 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[121 (1566901538596585472)]} 0 0
   [junit4]   2> 419704 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[122 (1566901538597634048)]} 0 0
   [junit4]   2> 419706 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[122 (1566901538598682624)]} 0 0
   [junit4]   2> 419707 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[123 (1566901538599731200)]} 0 0
   [junit4]   2> 419708 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[123 (1566901538600779776)]} 0 0
   [junit4]   2> 419710 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[124 (1566901538601828352)]} 0 1
   [junit4]   2> 419711 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[124 (1566901538603925504)]} 0 0
   [junit4]   2> 419712 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[125 (1566901538604974080)]} 0 0
   [junit4]   2> 419713 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[125 (1566901538607071232)]} 0 0
   [junit4]   2> 419714 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[126 (1566901538608119808)]} 0 0
   [junit4]   2> 419715 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[126 (1566901538609168384)]} 0 0
   [junit4]   2> 419717 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[127 (1566901538611265536)]} 0 0
   [junit4]   2> 419718 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[127 (1566901538612314112)]} 0 0
   [junit4]   2> 419719 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[128 (1566901538613362688)]} 0 0
   [junit4]   2> 419721 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[128 (1566901538614411264)]} 0 0
   [junit4]   2> 419722 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[129 (1566901538615459840)]} 0 0
   [junit4]   2> 419723 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[129 (1566901538616508416)]} 0 0
   [junit4]   2> 419724 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[130 (1566901538617556992)]} 0 0
   [junit4]   2> 419725 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[130 (1566901538619654144)]} 0 0
   [junit4]   2> 419726 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[131 (1566901538620702720)]} 0 0
   [junit4]   2> 419727 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[131 (1566901538621751296)]} 0 0
   [junit4]   2> 419728 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[132 (1566901538622799872)]} 0 0
   [junit4]   2> 419729 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[132 (1566901538623848448)]} 0 0
   [junit4]   2> 419731 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[133 (1566901538624897024)]} 0 0
   [junit4]   2> 419732 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[133 (1566901538625945600)]} 0 0
   [junit4]   2> 419733 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[134 (1566901538626994176)]} 0 0
   [junit4]   2> 419734 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[134 (1566901538628042752)]} 0 0
   [junit4]   2> 419735 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[135 (1566901538630139904)]} 0 0
   [junit4]   2> 419736 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[135 (1566901538630139904)]} 0 0
   [junit4]   2> 419737 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[136 (1566901538632237056)]} 0 0
   [junit4]   2> 419738 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[136 (1566901538633285632)]} 0 0
   [junit4]   2> 419739 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[137 (1566901538634334208)]} 0 0
   [junit4]   2> 419740 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[137 (1566901538635382784)]} 0 0
   [junit4]   2> 419741 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[138 (1566901538636431360)]} 0 0
   [junit4]   2> 419742 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[138 (1566901538637479936)]} 0 0
   [junit4]   2> 419744 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[139 (1566901538638528512)]} 0 0
   [junit4]   2> 419745 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[139 (1566901538639577088)]} 0 0
   [junit4]   2> 419746 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[140 (1566901538640625664)]} 0 0
   [junit4]   2> 419747 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[140 (1566901538641674240)]} 0 0
   [junit4]   2> 419748 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[141 (1566901538642722816)]} 0 0
   [junit4]   2> 419749 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[141 (1566901538643771392)]} 0 0
   [junit4]   2> 419750 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[142 (1566901538645868544)]} 0 0
   [junit4]   2> 419751 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[142 (1566901538646917120)]} 0 0
   [junit4]   2> 419752 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[143 (1566901538647965696)]} 0 0
   [junit4]   2> 419753 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[143 (1566901538649014272)]} 0 0
   [junit4]   2> 419754 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[144 (1566901538650062848)]} 0 0
   [junit4]   2> 419755 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[144 (1566901538651111424)]} 0 0
   [junit4]   2> 419757 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[145 (1566901538652160000)]} 0 0
   [junit4]   2> 419758 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[145 (1566901538654257152)]} 0 0
   [junit4]   2> 419760 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[146 (1566901538655305728)]} 0 0
   [junit4]   2> 419761 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[146 (1566901538656354304)]} 0 0
   [junit4]   2> 419762 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[147 (1566901538657402880)]} 0 0
   [junit4]   2> 419763 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[147 (1566901538658451456)]} 0 0
   [junit4]   2> 419764 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[148 (1566901538659500032)]} 0 0
   [junit4]   2> 419765 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[148 (1566901538660548608)]} 0 0
   [junit4]   2> 419766 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[149 (1566901538661597184)]} 0 0
   [junit4]   2> 419767 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={wt=javabin&version=2}{add=[149 (1566901538662645760)]} 0 0
   [junit4]   2> 419768 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 419768 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@302a2a7 commitCommandVersion:0
   [junit4]   2> 419802 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@385f3920[collection1] main]
   [junit4]   2> 419805 INFO  
(searcherExecutor-2095-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@385f3920[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C9)
 Uninverting(_1(7.0.0):C59)))}
   [junit4]   2> 419805 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 419805 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 37
   [junit4]   2> 419806 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 419806 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@510c3361 commitCommandVersion:0
   [junit4]   2> 419867 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@275b34ca[collection1] main]
   [junit4]   2> 419869 INFO  
(searcherExecutor-2106-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@275b34ca[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C9)
 Uninverting(_1(7.0.0):C59)))}
   [junit4]   2> 419870 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 419870 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/nqz/zp path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 63
   [junit4]   2> 419871 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.h.RequestHandlerBase Ignoring exception matching parameter cannot be 
negative
   [junit4]   2> 419871 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*&distrib=false&start=-1&wt=javabin&version=2} status=400 QTime=0
   [junit4]   2> 419872 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.h.RequestHandlerBase Ignoring exception matching parameter cannot be 
negative
   [junit4]   2> 419873 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*&distrib=false&start=0&rows=-1&wt=javabin&version=2} status=400 
QTime=0
   [junit4]   2> 419875 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_ti1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=1
   [junit4]   2> 419887 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_ti1+desc&shard.url=http://127.0.0.1:34476/nqz/zp/collection1&rows=10&version=2&q=*:*&NOW=1494313753874&isShard=true&wt=javabin}
 hits=68 status=0 QTime=1
   [junit4]   2> 419899 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313753874&ids=100,112,113,14,15,114,8,129,9,109&isShard=true&shard.url=http://127.0.0.1:34476/nqz/zp/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 419902 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=http://127.0.0.1:34476/nqz/zp/collection1&sort=n_ti1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=22
   [junit4]   2> 419904 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_ti1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 419993 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_ti1+asc&shard.url=[ff01::213]:33332/nqz/zp|[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::083]:33332/nqz/zp&rows=10&version=2&q=*:*&NOW=1494313753901&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 419996 INFO  (qtp749148671-4291) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313753901&ids=132,111,12,13,102,135,16,126,127,131&isShard=true&shard.url=[ff01::213]:33332/nqz/zp|[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::083]:33332/nqz/zp&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420001 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=[ff01::213]:33332/nqz/zp|[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::083]:33332/nqz/zp&sort=n_ti1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=93
   [junit4]   2> 420003 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_f1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=1
   [junit4]   2> 420007 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_f1+desc&shard.url=[ff01::213]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&rows=10&version=2&q=*:*&NOW=1494313753999&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420019 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313753999&ids=100,12,144,102,125,137,105,8,107,140&isShard=true&shard.url=[ff01::213]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420023 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=[ff01::213]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&sort=n_f1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=17
   [junit4]   2> 420024 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_f1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420078 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_f1+asc&shard.url=[ff01::114]:33332/nqz/zp|[ff01::083]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::213]:33332/nqz/zp&rows=10&version=2&q=*:*&NOW=1494313754020&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420081 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754020&ids=110,111,14,104,149,17,127,139,131,142&isShard=true&shard.url=[ff01::114]:33332/nqz/zp|[ff01::083]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::213]:33332/nqz/zp&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420082 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=[ff01::114]:33332/nqz/zp|[ff01::083]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::213]:33332/nqz/zp&sort=n_f1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=56
   [junit4]   2> 420084 INFO  (qtp1533618621-4280) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_tf1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420087 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tf1+desc&shard.url=[ff01::114]:33332/nqz/zp|[ff01::083]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&rows=10&version=2&q=*:*&NOW=1494313754080&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420093 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754080&ids=132,13,145,135,114,147,126,116,128,141&isShard=true&shard.url=[ff01::114]:33332/nqz/zp|[ff01::083]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420095 INFO  (qtp749148671-4291) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=[ff01::114]:33332/nqz/zp|[ff01::083]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&sort=n_tf1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=8
   [junit4]   2> 420096 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_tf1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420098 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tf1+asc&shard.url=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp|[ff01::083]:33332/nqz/zp&rows=10&version=2&q=*:*&NOW=1494313754091&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420100 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754091&ids=110,12,2,134,113,102,124,104,115,120&isShard=true&shard.url=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp|[ff01::083]:33332/nqz/zp&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420101 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp|[ff01::083]:33332/nqz/zp&sort=n_tf1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 420106 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_d1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=1
   [junit4]   2> 420109 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_d1+desc&shard.url=http://127.0.0.1:34476/nqz/zp/collection1&rows=10&version=2&q=*:*&NOW=1494313754101&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420112 INFO  (qtp749148671-4291) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754101&ids=110,145,102,4,136,6,108,109,141,10&isShard=true&shard.url=http://127.0.0.1:34476/nqz/zp/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420114 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=http://127.0.0.1:34476/nqz/zp/collection1&sort=n_d1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=7
   [junit4]   2> 420116 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_d1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420118 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_d1+asc&shard.url=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&rows=10&version=2&q=*:*&NOW=1494313754111&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420120 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754111&ids=11,144,2,101,146,124,103,148,115,120&isShard=true&shard.url=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420121 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&sort=n_d1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=4
   [junit4]   2> 420122 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_td1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420125 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_td1+desc&shard.url=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp|[ff01::213]:33332/nqz/zp&rows=10&version=2&q=*:*&NOW=1494313754118&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420127 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754118&ids=133,4,103,104,17,6,128,1001,118,119&isShard=true&shard.url=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp|[ff01::213]:33332/nqz/zp&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420128 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp|[ff01::213]:33332/nqz/zp&sort=n_td1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 420129 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_td1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420134 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_td1+asc&shard.url=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::083]:33332/nqz/zp|[ff01::213]:33332/nqz/zp&rows=10&version=2&q=*:*&NOW=1494313754127&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420153 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754127&ids=112,123,113,146,125,126,140,141,10,131&isShard=true&shard.url=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::083]:33332/nqz/zp|[ff01::213]:33332/nqz/zp&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420154 INFO  (qtp749148671-4291) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::083]:33332/nqz/zp|[ff01::213]:33332/nqz/zp&sort=n_td1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=21
   [junit4]   2> 420156 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_l1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420158 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_l1+desc&shard.url=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::213]:33332/nqz/zp|[ff01::114]:33332/nqz/zp|[ff01::083]:33332/nqz/zp&rows=10&version=2&q=*:*&NOW=1494313754151&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420160 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754151&ids=121,111,124,115,104,117,8,119,109,131&isShard=true&shard.url=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::213]:33332/nqz/zp|[ff01::114]:33332/nqz/zp|[ff01::083]:33332/nqz/zp&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420161 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::213]:33332/nqz/zp|[ff01::114]:33332/nqz/zp|[ff01::083]:33332/nqz/zp&sort=n_l1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 420162 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_l1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420164 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_l1+asc&shard.url=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp|[ff01::213]:33332/nqz/zp|[ff01::083]:33332/nqz/zp&rows=10&version=2&q=*:*&NOW=1494313754157&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420166 INFO  (qtp749148671-4291) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754157&ids=143,146,14,125,103,4,114,105,118,141&isShard=true&shard.url=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp|[ff01::213]:33332/nqz/zp|[ff01::083]:33332/nqz/zp&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420167 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp|[ff01::213]:33332/nqz/zp|[ff01::083]:33332/nqz/zp&sort=n_l1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 420168 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_tl1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420178 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tl1+desc&shard.url=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::083]:33332/nqz/zp&rows=10&version=2&q=*:*&NOW=1494313754171&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420181 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754171&ids=121,11,111,13,101,102,104,128,1001,9&isShard=true&shard.url=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::083]:33332/nqz/zp&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420182 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::083]:33332/nqz/zp&sort=n_tl1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=5
   [junit4]   2> 420183 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_tl1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420186 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tl1+asc&shard.url=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::213]:33332/nqz/zp|[ff01::083]:33332/nqz/zp&rows=10&version=2&q=*:*&NOW=1494313754179&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420187 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754179&ids=143,135,124,147,127,7,117,129,118,108&isShard=true&shard.url=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::213]:33332/nqz/zp|[ff01::083]:33332/nqz/zp&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420189 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::213]:33332/nqz/zp|[ff01::083]:33332/nqz/zp&sort=n_tl1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 420190 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_dt1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420193 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_dt1+desc&shard.url=[ff01::213]:33332/nqz/zp|[ff01::083]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp&rows=10&version=2&q=*:*&NOW=1494313754185&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420194 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754185&ids=133,144,14,137,149,138,8,119,140,131&isShard=true&shard.url=[ff01::213]:33332/nqz/zp|[ff01::083]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420195 INFO  (qtp749148671-4291) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=[ff01::213]:33332/nqz/zp|[ff01::083]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp&sort=n_dt1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 420197 INFO  (qtp1533618621-4279) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_dt1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420199 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_dt1+asc&shard.url=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp&rows=10&version=2&q=*:*&NOW=1494313754192&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420201 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754192&ids=132,143,100,13,123,113,146,3,1001,118&isShard=true&shard.url=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420202 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp&sort=n_dt1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 420203 INFO  (qtp1533618621-4276) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_tdt1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420207 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tdt1+desc&shard.url=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&rows=10&version=2&q=*:*&NOW=1494313754198&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420208 INFO  (qtp749148671-4295) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754198&ids=100,122,134,145,2,112,6,139,7,108&isShard=true&shard.url=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420216 INFO  (qtp749148671-4297) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&sort=n_tdt1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=11
   [junit4]   2> 420217 INFO  (qtp1533618621-4277) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=n_tdt1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420222 INFO  (qtp749148671-4296) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tdt1+asc&shard.url=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp&rows=10&version=2&q=*:*&NOW=1494313754215&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420224 INFO  (qtp749148671-4290) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754215&ids=132,133,146,4,125,148,1001,129,119,10&isShard=true&shard.url=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420224 INFO  (qtp749148671-4293) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=http://127.0.0.1:34476/nqz/zp/collection1|[ff01::114]:33332/nqz/zp&sort=n_tdt1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 420226 INFO  (qtp1533618621-4278) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort=a_i_p+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 420228 INFO  (qtp749148671-4291) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={df=text&distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=a_i_p+desc&shard.url=[ff01::213]:33332/nqz/zp|[ff01::083]:33332/nqz/zp|[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&rows=10&version=2&q=*:*&NOW=1494313754221&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 420230 INFO  (qtp749148671-4291) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&df=text&distrib=false&shards.purpose=64&NOW=1494313754221&ids=1,12,2,13,3,5,7,8,9,10&isShard=true&shard.url=[ff01::213]:33332/nqz/zp|[ff01::083]:33332/nqz/zp|[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 420231 INFO  (qtp749148671-4294) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&shards=[ff01::213]:33332/nqz/zp|[ff01::083]:33332/nqz/zp|[ff01::114]:33332/nqz/zp|http://127.0.0.1:34476/nqz/zp/collection1&sort=a_i_p+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 420233 INFO  (qtp1533618621-4273) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/nqz/zp path=/select 
params={q=*:*&distrib=false&sort={!func}testfunc(add(a_i_p,5))+d

[...truncated too long message...]

tor-2148-thread-1) [    x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING 
SolrCore org.apache.solr.core.SolrCore@62a7d655
   [junit4]   2> 451986 INFO  (coreCloseExecutor-2148-thread-1) [    
x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.collection1, tag=1655166549
   [junit4]   2> 451991 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@e73bc8f{/nqz/zp,null,UNAVAILABLE}
   [junit4]   2> 451993 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.e.j.s.AbstractConnector Stopped 
ServerConnector@78282801{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 451993 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=2031168896
   [junit4]   2> 451993 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 451993 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 451993 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 451993 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 451994 INFO  (coreCloseExecutor-2150-thread-1) [    
x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@4f557fec
   [junit4]   2> 452001 INFO  (coreCloseExecutor-2150-thread-1) [    
x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.collection1, tag=1331003372
   [junit4]   2> 452002 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@7a337940{/nqz/zp,null,UNAVAILABLE}
   [junit4]   2> 452003 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.e.j.s.AbstractConnector Stopped 
ServerConnector@53576552{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 452003 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=206119856
   [junit4]   2> 452003 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 452003 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 452003 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 452004 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 452004 INFO  (coreCloseExecutor-2152-thread-1) [    
x:collection1] o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@7b0a8193
   [junit4]   2> 452009 INFO  (coreCloseExecutor-2152-thread-1) [    
x:collection1] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.collection1, tag=2064286099
   [junit4]   2> 452010 INFO  
(TEST-TestDistributedSearch.test-seed#[45DF33F73737834A]) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@6ed0a680{/nqz/zp,null,UNAVAILABLE}
   [junit4]   2> NOTE: reproduce with: ant test  
-Dtestcase=TestDistributedSearch -Dtests.method=test 
-Dtests.seed=45DF33F73737834A -Dtests.multiplier=2 -Dtests.slow=true 
-Dtests.locale=fr-BE -Dtests.timezone=Etc/GMT-11 -Dtests.asserts=true 
-Dtests.file.encoding=US-ASCII
   [junit4] FAILURE 33.9s J0 | TestDistributedSearch.test <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: Expected to find 
shardAddress in the up shard info: 
{error=org.apache.solr.client.solrj.SolrServerException: Time allowed to handle 
this request exceeded,trace=org.apache.solr.client.solrj.SolrServerException: 
Time allowed to handle this request exceeded
   [junit4]    >        at 
org.apache.solr.client.solrj.impl.LBHttpSolrClient.request(LBHttpSolrClient.java:428)
   [junit4]    >        at 
org.apache.solr.handler.component.HttpShardHandlerFactory.makeLoadBalancedRequest(HttpShardHandlerFactory.java:255)
   [junit4]    >        at 
org.apache.solr.handler.component.HttpShardHandler.lambda$submit$0(HttpShardHandler.java:166)
   [junit4]    >        at 
java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [junit4]    >        at 
java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
   [junit4]    >        at 
java.util.concurrent.FutureTask.run(FutureTask.java:266)
   [junit4]    >        at 
com.codahale.metrics.InstrumentedExecutorService$InstrumentedRunnable.run(InstrumentedExecutorService.java:176)
   [junit4]    >        at 
org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
   [junit4]    >        at 
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
   [junit4]    >        at 
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
   [junit4]    >        at java.lang.Thread.run(Thread.java:745)
   [junit4]    > ,time=1}
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([45DF33F73737834A:CD8B0C2D99CBEEB2]:0)
   [junit4]    >        at 
org.apache.solr.TestDistributedSearch.comparePartialResponses(TestDistributedSearch.java:1186)
   [junit4]    >        at 
org.apache.solr.TestDistributedSearch.queryPartialResults(TestDistributedSearch.java:1127)
   [junit4]    >        at 
org.apache.solr.TestDistributedSearch.test(TestDistributedSearch.java:987)
   [junit4]    >        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsRepeatStatement.callStatement(BaseDistributedSearchTestCase.java:1011)
   [junit4]    >        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:960)
   [junit4]    >        at java.lang.Thread.run(Thread.java:745)
   [junit4]   2> 452013 INFO  
(SUITE-TestDistributedSearch-seed#[45DF33F73737834A]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.TestDistributedSearch_45DF33F73737834A-001
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): 
{other_tl1=FST50, range_facet_l_dv=PostingsFormat(name=Memory), 
SubjectTerms_mfacet=FST50, n_l1=FST50, a_n_tdt=PostingsFormat(name=Memory), 
multiDefault=PostingsFormat(name=Memory), intDefault=FST50, 
n_td1=PostingsFormat(name=Memory), n_d1=FST50, 
n_f1=PostingsFormat(name=Memory), range_facet_l=FST50, 
n_tl1=PostingsFormat(name=Memory), a_s=Lucene50(blocksize=128), 
oddField_s=Lucene50(blocksize=128), n_tf1=FST50, 
lowerfilt1and2=PostingsFormat(name=Memory), a_t=FST50, 
lowerfilt=PostingsFormat(name=Memory), id=PostingsFormat(name=Memory), 
text=Lucene50(blocksize=128), timestamp=FST50, 
severity=Lucene50(blocksize=128), foo_sev_enum=PostingsFormat(name=Memory), 
n_dt1=PostingsFormat(name=Memory), b_n_tdt=FST50, 
n_ti1=PostingsFormat(name=Memory), rnd_b=PostingsFormat(name=Memory), 
foo_b=Lucene50(blocksize=128), n_tdt1=FST50, foo_d=PostingsFormat(name=Memory), 
range_facet_i_dv=FST50, foo_f=Lucene50(blocksize=128)}, 
docValues:{range_facet_l_dv=DocValuesFormat(name=Asserting), 
foo_sev_enum=DocValuesFormat(name=Asserting), 
_version_=DocValuesFormat(name=Direct), 
range_facet_i_dv=DocValuesFormat(name=Direct), 
intDvoDefault=DocValuesFormat(name=Lucene70), 
timestamp=DocValuesFormat(name=Direct), a_i_p=DocValuesFormat(name=Lucene70)}, 
maxPointsInLeafNode=1896, maxMBSortInHeap=5.722176310123738, 
sim=RandomSimilarity(queryNorm=true): {}, locale=fr-BE, timezone=Etc/GMT-11
   [junit4]   2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 
1.8.0_121 (64-bit)/cpus=4,threads=1,free=77470840,total=530579456
   [junit4]   2> NOTE: All tests run in this JVM: 
[TestHighFrequencyDictionaryFactory, TestObjectReleaseTracker, 
SolrMetricManagerTest, TestDistribDocBasedVersion, TestHighlightDedupGrouping, 
MultiTermTest, TestTrieFacet, SolrSlf4jReporterTest, TestCodecSupport, 
PeerSyncTest, CloneFieldUpdateProcessorFactoryTest, 
TestSolrCloudWithKerberosAlt, TestHalfAndHalfDocValues, 
TestJavabinTupleStreamParser, SolrCoreTest, TestRequestStatusCollectionAPI, 
TestDynamicFieldCollectionResource, TestCSVLoader, TestShortCircuitedRequests, 
TestMiniSolrCloudCluster, AddSchemaFieldsUpdateProcessorFactoryTest, 
FastVectorHighlighterTest, RAMDirectoryFactoryTest, RequiredFieldsTest, 
ZkStateWriterTest, TestExceedMaxTermLength, TestFoldingMultitermQuery, 
TestReloadDeadlock, TemplateUpdateProcessorTest, TestPivotHelperCode, 
TestReplicationHandlerBackup, TestConfigSetsAPIZkFailure, 
TestSolrQueryParserResource, MinimalSchemaTest, 
OverriddenZkACLAndCredentialsProvidersTest, NodeMutatorTest, 
TestRebalanceLeaders, PeerSyncReplicationTest, TestLazyCores, 
ConjunctionSolrSpellCheckerTest, SecurityConfHandlerTest, 
SpatialRPTFieldTypeTest, BufferStoreTest, AliasIntegrationTest, SyncSliceTest, 
DistribJoinFromCollectionTest, DistributedFacetPivotSmallAdvancedTest, 
TestManagedSchemaThreadSafety, SubstringBytesRefFilterTest, 
VMParamsZkACLAndCredentialsProvidersTest, TestSolr4Spatial, 
SortSpecParsingTest, XsltUpdateRequestHandlerTest, 
LeaderElectionContextKeyTest, TestFastWriter, TestStressLucene, 
PathHierarchyTokenizerFactoryTest, TestLMJelinekMercerSimilarityFactory, 
SimpleCollectionCreateDeleteTest, TestDistributedSearch]
   [junit4] Completed [164/709 (1!)] on J0 in 33.97s, 1 test, 1 failure <<< 
FAILURES!

[...truncated 45129 lines...]

---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org