[JENKINS-EA] Lucene-Solr-6.x-Linux (64bit/jdk-9-ea+136) - Build # 1831 - Unstable!

Thu, 29 Sep 2016 08:57:42 -0700 

Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Linux/1831/
Java: 64bit/jdk-9-ea+136 -XX:-UseCompressedOops -XX:+UseSerialGC

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

Error Message:
Expected to find shardAddress in the up shard info

Stack Trace:
java.lang.AssertionError: Expected to find shardAddress in the up shard info
        at 
__randomizedtesting.SeedInfo.seed([73E86667E3AB2998:FBBC59BD4D574460]: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:1162)
        at 
org.apache.solr.TestDistributedSearch.queryPartialResults(TestDistributedSearch.java:1103)
        at 
org.apache.solr.TestDistributedSearch.test(TestDistributedSearch.java:963)
        at 
jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@9-ea/Native 
Method)
        at 
jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@9-ea/NativeMethodAccessorImpl.java:62)
        at 
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@9-ea/DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(java.base@9-ea/Method.java:535)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1764)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsRepeatStatement.callStatement(BaseDistributedSearchTestCase.java:1018)
        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
        at 
com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
        at 
org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
        at java.lang.Thread.run(java.base@9-ea/Thread.java:843)




Build Log:
[...truncated 11683 lines...]
   [junit4] Suite: org.apache.solr.TestDistributedSearch
   [junit4]   2> Creating dataDir: 
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.TestDistributedSearch_73E86667E3AB2998-001/init-core-data-001
   [junit4]   2> 1169175 INFO  
(SUITE-TestDistributedSearch-seed#[73E86667E3AB2998]-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> 1169176 INFO  
(SUITE-TestDistributedSearch-seed#[73E86667E3AB2998]-worker) [    ] 
o.a.s.BaseDistributedSearchTestCase Setting hostContext system property: /alc/
   [junit4]   2> 1169233 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.TestDistributedSearch_73E86667E3AB2998-001/tempDir-001/control/cores/collection1
   [junit4]   2> 1169234 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] o.e.j.s.Server 
jetty-9.3.8.v20160314
   [junit4]   2> 1169234 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@53fd53da{/alc,null,AVAILABLE}
   [junit4]   2> 1169235 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.e.j.s.ServerConnector Started 
ServerConnector@78598949{HTTP/1.1,[http/1.1]}{127.0.0.1:37831}
   [junit4]   2> 1169235 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] o.e.j.s.Server 
Started @1172418ms
   [junit4]   2> 1169235 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/alc, 
hostPort=37831, 
coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.TestDistributedSearch_73E86667E3AB2998-001/tempDir-001/control/cores}
   [junit4]   2> 1169236 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.3.0
   [junit4]   2> 1169236 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in standalone mode on 
port null
   [junit4]   2> 1169236 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1169236 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2016-09-29T15:24:16.374233Z
   [junit4]   2> 1169236 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.TestDistributedSearch_73E86667E3AB2998-001/tempDir-001/control/solr.xml
   [junit4]   2> 1169244 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1169245 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.TestDistributedSearch_73E86667E3AB2998-001/tempDir-001/control/cores
   [junit4]   2> 1169246 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 1169246 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: 
[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/lib,
 
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 1169268 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.3.0
   [junit4]   2> 1169285 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 1169371 WARN  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] default search field in schema is text. 
WARNING: Deprecated, please use 'df' on request instead.
   [junit4]   2> 1169373 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 1169378 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
configset 
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1
   [junit4]   2> 1169378 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.TestDistributedSearch_73E86667E3AB2998-001/tempDir-001/control/cores/collection1/data/]
   [junit4]   2> 1169378 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5509c09b
   [junit4]   2> 1169379 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=31, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.21499501551564607]
   [junit4]   2> 1169388 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1169388 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1169388 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1169388 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1169388 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=45, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=33.0556640625, 
floorSegmentMB=0.3076171875, forceMergeDeletesPctAllowed=21.06635751746407, 
segmentsPerTier=41.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.7578030694637252
   [junit4]   2> 1169389 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@33e0d578[collection1] main]
   [junit4]   2> 1169389 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 1169426 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.s.DirectSolrSpellChecker init: 
{name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 1169607 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1169608 INFO  (searcherExecutor-6990-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 1169608 INFO  (searcherExecutor-6990-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 1169608 INFO  (searcherExecutor-6990-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 1169608 INFO  (searcherExecutor-6990-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: 
multipleFields
   [junit4]   2> 1169608 INFO  (coreLoadExecutor-6989-thread-1) [    ] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1546820157960093696
   [junit4]   2> 1169608 INFO  (searcherExecutor-6990-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 1169608 INFO  (searcherExecutor-6990-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 1169608 INFO  (searcherExecutor-6990-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 1169608 INFO  (searcherExecutor-6990-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 1169609 INFO  (searcherExecutor-6990-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 1169609 INFO  (searcherExecutor-6990-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@33e0d578[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1169806 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.TestDistributedSearch_73E86667E3AB2998-001/tempDir-001/shard0/cores/collection1
   [junit4]   2> 1169807 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] o.e.j.s.Server 
jetty-9.3.8.v20160314
   [junit4]   2> 1169807 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@b758b57{/alc,null,AVAILABLE}
   [junit4]   2> 1169808 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.e.j.s.ServerConnector Started 
ServerConnector@7d5cda3c{HTTP/1.1,[http/1.1]}{127.0.0.1:46101}
   [junit4]   2> 1169808 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] o.e.j.s.Server 
Started @1172991ms
   [junit4]   2> 1169808 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/alc, 
hostPort=46101, 
coreRootDirectory=/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.TestDistributedSearch_73E86667E3AB2998-001/tempDir-001/shard0/cores}
   [junit4]   2> 1169809 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
6.3.0
   [junit4]   2> 1169809 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in standalone mode on 
port null
   [junit4]   2> 1169809 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 1169809 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2016-09-29T15:24:16.947223Z
   [junit4]   2> 1169809 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.TestDistributedSearch_73E86667E3AB2998-001/tempDir-001/shard0/solr.xml
   [junit4]   2> 1169813 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: 
socketTimeout=340000&connTimeout=45000&retry=true
   [junit4]   2> 1169814 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.TestDistributedSearch_73E86667E3AB2998-001/tempDir-001/shard0/cores
   [junit4]   2> 1169814 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 1169815 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.c.SolrResourceLoader [null] Added 2 libs to classloader, from paths: 
[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/lib,
 
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1/lib/classes]
   [junit4]   2> 1169834 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.3.0
   [junit4]   2> 1169851 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] Schema name=test
   [junit4]   2> 1169939 WARN  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] default search field in schema is text. 
WARNING: Deprecated, please use 'df' on request instead.
   [junit4]   2> 1169941 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.s.IndexSchema Loaded schema test/1.0 with uniqueid field id
   [junit4]   2> 1169945 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
configset 
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1
   [junit4]   2> 1169945 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/core/src/test-files/solr/collection1],
 
dataDir=[/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.TestDistributedSearch_73E86667E3AB2998-001/tempDir-001/shard0/cores/collection1/data/]
   [junit4]   2> 1169945 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.c.JmxMonitoredMap JMX monitoring is enabled. Adding Solr mbeans to JMX 
Server: com.sun.jmx.mbeanserver.JmxMBeanServer@5509c09b
   [junit4]   2> 1169945 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.LogDocMergePolicy: [LogDocMergePolicy: 
minMergeSize=1000, mergeFactor=31, maxMergeSize=9223372036854775807, 
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=false, 
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.21499501551564607]
   [junit4]   2> 1169955 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 1169955 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH 
numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
   [junit4]   2> 1169956 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 1169956 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 1169956 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=45, maxMergeAtOnceExplicit=21, maxMergedSegmentMB=33.0556640625, 
floorSegmentMB=0.3076171875, forceMergeDeletesPctAllowed=21.06635751746407, 
segmentsPerTier=41.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.7578030694637252
   [junit4]   2> 1169956 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@463ac4f8[collection1] main]
   [junit4]   2> 1169957 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 1170042 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.s.DirectSolrSpellChecker init: 
{name=direct,classname=DirectSolrSpellChecker,field=lowerfilt,minQueryLength=3}
   [junit4]   2> 1170252 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 1170252 INFO  (searcherExecutor-7001-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 1170252 INFO  (searcherExecutor-7001-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: direct
   [junit4]   2> 1170252 INFO  (searcherExecutor-7001-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 1170252 INFO  (searcherExecutor-7001-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: 
multipleFields
   [junit4]   2> 1170252 INFO  (searcherExecutor-7001-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: jarowinkler
   [junit4]   2> 1170253 INFO  (coreLoadExecutor-7000-thread-1) [    ] 
o.a.s.u.UpdateLog Could not find max version in index or recent updates, using 
new clock 1546820158636425216
   [junit4]   2> 1170253 INFO  (searcherExecutor-7001-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: external
   [junit4]   2> 1170253 INFO  (searcherExecutor-7001-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: freq
   [junit4]   2> 1170253 INFO  (searcherExecutor-7001-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: fqcn
   [junit4]   2> 1170253 INFO  (searcherExecutor-7001-thread-1) [    ] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: perDict
   [junit4]   2> 1170253 INFO  (searcherExecutor-7001-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@463ac4f8[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 1170315 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting test
   [junit4]   2> 1170318 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{deleteByQuery=*:* (-1546820158703534080)} 0 1
   [junit4]   2> 1170319 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{deleteByQuery=*:* (-1546820158705631232)} 0 0
   [junit4]   2> 1170323 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[1 (1546820158707728384)]} 0 2
   [junit4]   2> 1170325 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[1 (1546820158710874112)]} 0 0
   [junit4]   2> 1170327 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[2 (1546820158714019840)]} 0 0
   [junit4]   2> 1170329 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[2 (1546820158715068416)]} 0 0
   [junit4]   2> 1170330 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[3 (1546820158717165568)]} 0 0
   [junit4]   2> 1170332 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[3 (1546820158719262720)]} 0 0
   [junit4]   2> 1170334 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[4 (1546820158720311296)]} 0 0
   [junit4]   2> 1170336 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[4 (1546820158723457024)]} 0 0
   [junit4]   2> 1170338 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[5 (1546820158724505600)]} 0 0
   [junit4]   2> 1170340 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[5 (1546820158726602752)]} 0 0
   [junit4]   2> 1170341 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[6 (1546820158728699904)]} 0 0
   [junit4]   2> 1170343 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[6 (1546820158729748480)]} 0 0
   [junit4]   2> 1170344 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[7 (1546820158731845632)]} 0 0
   [junit4]   2> 1170346 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[7 (1546820158733942784)]} 0 0
   [junit4]   2> 1170348 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[8 (1546820158736039936)]} 0 0
   [junit4]   2> 1170350 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[8 (1546820158738137088)]} 0 0
   [junit4]   2> 1170352 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[9 (1546820158740234240)]} 0 0
   [junit4]   2> 1170354 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[9 (1546820158741282816)]} 0 0
   [junit4]   2> 1170355 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1170355 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@7db11988
   [junit4]   2> 1170360 INFO  (qtp582142779-73104) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@22b964d0[collection1] main]
   [junit4]   2> 1170360 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1170361 INFO  (searcherExecutor-6990-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@22b964d0[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.3.0):c9)))}
   [junit4]   2> 1170361 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 5
   [junit4]   2> 1170362 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1170362 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@6d4f5d0f
   [junit4]   2> 1170364 INFO  (qtp980594094-73121) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@18552481[collection1] main]
   [junit4]   2> 1170365 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1170365 INFO  (searcherExecutor-7001-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@18552481[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.3.0):c9)))}
   [junit4]   2> 1170365 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 2
   [junit4]   2> 1170368 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[10 (1546820158755962880)]} 0 1
   [junit4]   2> 1170370 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[10 (1546820158758060032)]} 0 1
   [junit4]   2> 1170372 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[11 (1546820158761205760)]} 0 0
   [junit4]   2> 1170374 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[11 (1546820158763302912)]} 0 0
   [junit4]   2> 1170376 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[12 (1546820158765400064)]} 0 0
   [junit4]   2> 1170377 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[12 (1546820158766448640)]} 0 0
   [junit4]   2> 1170379 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[13 (1546820158768545792)]} 0 0
   [junit4]   2> 1170381 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[13 (1546820158770642944)]} 0 0
   [junit4]   2> 1170383 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[1001 (1546820158771691520)]} 0 0
   [junit4]   2> 1170384 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[1001 (1546820158773788672)]} 0 0
   [junit4]   2> 1170386 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[14 (1546820158775885824)]} 0 0
   [junit4]   2> 1170388 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[14 (1546820158777982976)]} 0 0
   [junit4]   2> 1170390 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[15 (1546820158780080128)]} 0 0
   [junit4]   2> 1170391 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[15 (1546820158781128704)]} 0 0
   [junit4]   2> 1170393 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[16 (1546820158783225856)]} 0 0
   [junit4]   2> 1170395 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[16 (1546820158785323008)]} 0 0
   [junit4]   2> 1170397 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[17 (1546820158786371584)]} 0 0
   [junit4]   2> 1170398 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[17 (1546820158788468736)]} 0 0
   [junit4]   2> 1170400 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[100 (1546820158790565888)]} 0 0
   [junit4]   2> 1170401 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[100 (1546820158791614464)]} 0 0
   [junit4]   2> 1170403 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[101 (1546820158793711616)]} 0 0
   [junit4]   2> 1170404 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[101 (1546820158794760192)]} 0 0
   [junit4]   2> 1170406 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[102 (1546820158796857344)]} 0 0
   [junit4]   2> 1170408 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[102 (1546820158798954496)]} 0 0
   [junit4]   2> 1170409 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[103 (1546820158800003072)]} 0 0
   [junit4]   2> 1170411 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[103 (1546820158802100224)]} 0 0
   [junit4]   2> 1170413 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[104 (1546820158804197376)]} 0 0
   [junit4]   2> 1170414 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[104 (1546820158805245952)]} 0 0
   [junit4]   2> 1170416 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[105 (1546820158807343104)]} 0 0
   [junit4]   2> 1170418 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[105 (1546820158808391680)]} 0 0
   [junit4]   2> 1170419 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[106 (1546820158810488832)]} 0 0
   [junit4]   2> 1170421 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[106 (1546820158812585984)]} 0 0
   [junit4]   2> 1170423 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[107 (1546820158814683136)]} 0 0
   [junit4]   2> 1170424 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[107 (1546820158815731712)]} 0 0
   [junit4]   2> 1170426 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[108 (1546820158817828864)]} 0 0
   [junit4]   2> 1170428 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[108 (1546820158818877440)]} 0 0
   [junit4]   2> 1170429 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[109 (1546820158820974592)]} 0 0
   [junit4]   2> 1170431 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[109 (1546820158823071744)]} 0 0
   [junit4]   2> 1170432 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[110 (1546820158824120320)]} 0 0
   [junit4]   2> 1170434 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[110 (1546820158826217472)]} 0 0
   [junit4]   2> 1170436 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[111 (1546820158828314624)]} 0 0
   [junit4]   2> 1170437 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[111 (1546820158829363200)]} 0 0
   [junit4]   2> 1170439 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[112 (1546820158831460352)]} 0 0
   [junit4]   2> 1170441 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[112 (1546820158832508928)]} 0 0
   [junit4]   2> 1170443 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[113 (1546820158835654656)]} 0 0
   [junit4]   2> 1170445 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[113 (1546820158837751808)]} 0 0
   [junit4]   2> 1170446 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[114 (1546820158838800384)]} 0 0
   [junit4]   2> 1170448 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[114 (1546820158840897536)]} 0 0
   [junit4]   2> 1170449 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[115 (1546820158841946112)]} 0 0
   [junit4]   2> 1170451 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[115 (1546820158844043264)]} 0 0
   [junit4]   2> 1170453 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[116 (1546820158846140416)]} 0 0
   [junit4]   2> 1170455 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[116 (1546820158848237568)]} 0 0
   [junit4]   2> 1170457 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[117 (1546820158849286144)]} 0 0
   [junit4]   2> 1170458 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[117 (1546820158851383296)]} 0 0
   [junit4]   2> 1170460 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[118 (1546820158853480448)]} 0 0
   [junit4]   2> 1170461 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[118 (1546820158854529024)]} 0 0
   [junit4]   2> 1170463 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[119 (1546820158856626176)]} 0 0
   [junit4]   2> 1170465 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[119 (1546820158858723328)]} 0 0
   [junit4]   2> 1170467 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[120 (1546820158860820480)]} 0 0
   [junit4]   2> 1170469 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[120 (1546820158862917632)]} 0 0
   [junit4]   2> 1170470 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[121 (1546820158863966208)]} 0 0
   [junit4]   2> 1170472 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[121 (1546820158866063360)]} 0 0
   [junit4]   2> 1170474 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[122 (1546820158867111936)]} 0 0
   [junit4]   2> 1170475 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[122 (1546820158869209088)]} 0 0
   [junit4]   2> 1170477 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[123 (1546820158871306240)]} 0 0
   [junit4]   2> 1170479 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[123 (1546820158873403392)]} 0 0
   [junit4]   2> 1170480 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[124 (1546820158874451968)]} 0 0
   [junit4]   2> 1170482 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[124 (1546820158876549120)]} 0 0
   [junit4]   2> 1170484 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[125 (1546820158878646272)]} 0 0
   [junit4]   2> 1170486 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[125 (1546820158879694848)]} 0 0
   [junit4]   2> 1170487 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[126 (1546820158881792000)]} 0 0
   [junit4]   2> 1170489 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[126 (1546820158883889152)]} 0 0
   [junit4]   2> 1170491 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[127 (1546820158885986304)]} 0 0
   [junit4]   2> 1170492 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[127 (1546820158887034880)]} 0 0
   [junit4]   2> 1170494 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[128 (1546820158889132032)]} 0 0
   [junit4]   2> 1170495 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[128 (1546820158890180608)]} 0 0
   [junit4]   2> 1170497 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[129 (1546820158892277760)]} 0 0
   [junit4]   2> 1170499 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[129 (1546820158893326336)]} 0 0
   [junit4]   2> 1170500 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[130 (1546820158895423488)]} 0 0
   [junit4]   2> 1170502 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[130 (1546820158897520640)]} 0 0
   [junit4]   2> 1170504 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[131 (1546820158899617792)]} 0 0
   [junit4]   2> 1170506 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[131 (1546820158901714944)]} 0 0
   [junit4]   2> 1170508 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[132 (1546820158902763520)]} 0 0
   [junit4]   2> 1170509 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[132 (1546820158904860672)]} 0 0
   [junit4]   2> 1170511 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[133 (1546820158905909248)]} 0 0
   [junit4]   2> 1170512 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[133 (1546820158908006400)]} 0 0
   [junit4]   2> 1170514 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[134 (1546820158910103552)]} 0 0
   [junit4]   2> 1170516 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[134 (1546820158912200704)]} 0 0
   [junit4]   2> 1170518 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[135 (1546820158914297856)]} 0 0
   [junit4]   2> 1170520 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[135 (1546820158915346432)]} 0 0
   [junit4]   2> 1170521 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[136 (1546820158917443584)]} 0 0
   [junit4]   2> 1170523 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[136 (1546820158919540736)]} 0 0
   [junit4]   2> 1170524 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[137 (1546820158920589312)]} 0 0
   [junit4]   2> 1170526 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[137 (1546820158922686464)]} 0 0
   [junit4]   2> 1170528 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[138 (1546820158924783616)]} 0 0
   [junit4]   2> 1170530 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[138 (1546820158926880768)]} 0 0
   [junit4]   2> 1170532 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[139 (1546820158928977920)]} 0 0
   [junit4]   2> 1170534 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[139 (1546820158930026496)]} 0 0
   [junit4]   2> 1170535 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[140 (1546820158932123648)]} 0 0
   [junit4]   2> 1170537 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[140 (1546820158934220800)]} 0 0
   [junit4]   2> 1170538 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[141 (1546820158935269376)]} 0 0
   [junit4]   2> 1170540 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[141 (1546820158937366528)]} 0 0
   [junit4]   2> 1170542 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[142 (1546820158938415104)]} 0 0
   [junit4]   2> 1170543 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[142 (1546820158940512256)]} 0 0
   [junit4]   2> 1170545 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[143 (1546820158942609408)]} 0 0
   [junit4]   2> 1170546 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[143 (1546820158943657984)]} 0 0
   [junit4]   2> 1170548 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[144 (1546820158945755136)]} 0 0
   [junit4]   2> 1170549 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[144 (1546820158946803712)]} 0 0
   [junit4]   2> 1170551 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[145 (1546820158948900864)]} 0 0
   [junit4]   2> 1170553 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[145 (1546820158950998016)]} 0 0
   [junit4]   2> 1170554 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[146 (1546820158952046592)]} 0 0
   [junit4]   2> 1170556 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[146 (1546820158954143744)]} 0 0
   [junit4]   2> 1170557 INFO  (qtp582142779-73097) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[147 (1546820158955192320)]} 0 0
   [junit4]   2> 1170559 INFO  (qtp980594094-73114) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[147 (1546820158957289472)]} 0 0
   [junit4]   2> 1170560 INFO  (qtp582142779-73102) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[148 (1546820158958338048)]} 0 0
   [junit4]   2> 1170562 INFO  (qtp980594094-73119) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[148 (1546820158960435200)]} 0 0
   [junit4]   2> 1170564 INFO  (qtp582142779-73103) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[149 (1546820158962532352)]} 0 0
   [junit4]   2> 1170566 INFO  (qtp980594094-73120) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={wt=javabin&version=2}{add=[149 (1546820158964629504)]} 0 0
   [junit4]   2> 1170567 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1170567 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@7db11988
   [junit4]   2> 1170572 INFO  (qtp582142779-73104) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@df85296[collection1] main]
   [junit4]   2> 1170572 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1170573 INFO  (searcherExecutor-6990-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@df85296[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.3.0):c9)
 Uninverting(_1(6.3.0):c59)))}
   [junit4]   2> 1170573 INFO  (qtp582142779-73104) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 5
   [junit4]   2> 1170575 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 1170575 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@6d4f5d0f
   [junit4]   2> 1170579 INFO  (qtp980594094-73121) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@4cba7305[collection1] main]
   [junit4]   2> 1170580 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 1170580 INFO  (searcherExecutor-7001-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@4cba7305[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.3.0):c9)
 Uninverting(_1(6.3.0):c59)))}
   [junit4]   2> 1170580 INFO  (qtp980594094-73121) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/alc path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 5
   [junit4]   2> 1170582 INFO  (qtp582142779-73097) [    ] 
o.a.s.h.RequestHandlerBase Ignoring exception matching parameter cannot be 
negative
   [junit4]   2> 1170582 INFO  (qtp582142779-73097) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*&distrib=false&start=-1&wt=javabin&version=2} status=400 QTime=0
   [junit4]   2> 1170584 INFO  (qtp582142779-73102) [    ] 
o.a.s.h.RequestHandlerBase Ignoring exception matching parameter cannot be 
negative
   [junit4]   2> 1170584 INFO  (qtp582142779-73102) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*&distrib=false&start=0&rows=-1&wt=javabin&version=2} status=400 
QTime=0
   [junit4]   2> 1170586 INFO  (qtp582142779-73103) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_ti1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170591 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_ti1+desc&shard.url=[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1&rows=10&version=2&q=*:*&NOW=1475162657727&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170594 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657727&ids=110,111,100,112,135,102,147,149,107,109&isShard=true&shard.url=[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170596 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1&sort=n_ti1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=7
   [junit4]   2> 1170599 INFO  (qtp582142779-73104) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_ti1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170608 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_ti1+asc&shard.url=[ff01::213]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&rows=10&version=2&q=*:*&NOW=1475162657739&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170611 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657739&ids=11,103,15,16,6,105,128,106,7,129&isShard=true&shard.url=[ff01::213]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170615 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::213]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&sort=n_ti1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=13
   [junit4]   2> 1170617 INFO  (qtp582142779-73097) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_f1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170621 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_f1+desc&shard.url=[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657757&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170623 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657757&ids=1,2,146,137,115,5,1001,7,119,142&isShard=true&shard.url=[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170626 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc&sort=n_f1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=6
   [junit4]   2> 1170628 INFO  (qtp582142779-73102) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_f1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170633 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_f1+asc&shard.url=[ff01::083]:33332/alc|[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657768&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170635 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657768&ids=134,145,15,4,126,127,17,9,141,120&isShard=true&shard.url=[ff01::083]:33332/alc|[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170638 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::083]:33332/alc|[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc&sort=n_f1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=8
   [junit4]   2> 1170640 INFO  (qtp582142779-73103) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_tf1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170644 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tf1+desc&shard.url=[ff01::213]:33332/alc|[ff01::114]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&rows=10&version=2&q=*:*&NOW=1475162657780&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170647 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657780&ids=122,134,3,147,125,137,149,108,141,10&isShard=true&shard.url=[ff01::213]:33332/alc|[ff01::114]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170649 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::213]:33332/alc|[ff01::114]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&sort=n_tf1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=6
   [junit4]   2> 1170650 INFO  (qtp582142779-73104) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_tf1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170654 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tf1+asc&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657790&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170656 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657790&ids=111,146,113,4,136,16,126,17,139,109&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170656 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc&sort=n_tf1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=4
   [junit4]   2> 1170659 INFO  (qtp582142779-73097) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_d1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170663 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_d1+desc&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::213]:33332/alc|[ff01::114]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657799&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170665 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657799&ids=122,1,111,123,134,136,5,128,108,141&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::213]:33332/alc|[ff01::114]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170665 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::213]:33332/alc|[ff01::114]:33332/alc&sort=n_d1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=4
   [junit4]   2> 1170667 INFO  (qtp582142779-73102) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_d1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170671 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_d1+asc&shard.url=[ff01::213]:33332/alc|[ff01::114]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&rows=10&version=2&q=*:*&NOW=1475162657807&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170673 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657807&ids=132,102,124,125,17,106,118,109,130,131&isShard=true&shard.url=[ff01::213]:33332/alc|[ff01::114]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170674 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::213]:33332/alc|[ff01::114]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&sort=n_d1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=4
   [junit4]   2> 1170676 INFO  (qtp582142779-73103) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_td1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170679 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_td1+desc&shard.url=[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1&rows=10&version=2&q=*:*&NOW=1475162657815&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170681 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657815&ids=132,11,144,113,15,114,147,117,106,129&isShard=true&shard.url=[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170681 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1&sort=n_td1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=4
   [junit4]   2> 1170683 INFO  (qtp582142779-73104) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_td1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170686 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_td1+asc&shard.url=[ff01::213]:33332/alc|http://127.0.0.1:46101/alc/collection1&rows=10&version=2&q=*:*&NOW=1475162657823&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170688 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657823&ids=134,112,102,136,104,16,139,8,108,141&isShard=true&shard.url=[ff01::213]:33332/alc|http://127.0.0.1:46101/alc/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170689 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::213]:33332/alc|http://127.0.0.1:46101/alc/collection1&sort=n_td1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 1170691 INFO  (qtp582142779-73097) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_l1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170694 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_l1+desc&shard.url=[ff01::213]:33332/alc|[ff01::114]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&rows=10&version=2&q=*:*&NOW=1475162657830&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170696 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657830&ids=110,133,134,13,114,6,9,119,130,120&isShard=true&shard.url=[ff01::213]:33332/alc|[ff01::114]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170697 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::213]:33332/alc|[ff01::114]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&sort=n_l1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=4
   [junit4]   2> 1170698 INFO  (qtp582142779-73102) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_l1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170702 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_l1+asc&shard.url=http://127.0.0.1:46101/alc/collection1&rows=10&version=2&q=*:*&NOW=1475162657838&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170704 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657838&ids=121,145,147,103,125,115,7,1001,129,109&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170704 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=http://127.0.0.1:46101/alc/collection1&sort=n_l1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 1170706 INFO  (qtp582142779-73103) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_tl1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170710 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tl1+desc&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::213]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657846&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170712 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657846&ids=11,133,12,101,102,125,16,138,149,106&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::213]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170712 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::213]:33332/alc&sort=n_tl1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=4
   [junit4]   2> 1170714 INFO  (qtp582142779-73104) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_tl1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170718 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tl1+asc&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657854&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170720 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657854&ids=143,144,100,3,14,17,127,119,120,142&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170721 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc&sort=n_tl1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=4
   [junit4]   2> 1170722 INFO  (qtp582142779-73097) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_dt1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170726 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_dt1+desc&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::114]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657862&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170728 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657862&ids=132,121,111,134,145,135,114,106,117,10&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::114]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170728 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::114]:33332/alc&sort=n_dt1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 1170730 INFO  (qtp582142779-73102) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_dt1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170734 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_dt1+asc&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::114]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657870&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170735 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657870&ids=133,124,3,15,4,103,137,17,8,130&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::114]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170736 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=http://127.0.0.1:46101/alc/collection1|[ff01::114]:33332/alc&sort=n_dt1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 1170738 INFO  (qtp582142779-73103) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_tdt1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170741 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tdt1+desc&shard.url=http://127.0.0.1:46101/alc/collection1&rows=10&version=2&q=*:*&NOW=1475162657877&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170743 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657877&ids=132,133,5,104,115,6,106,117,107,10&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170743 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=http://127.0.0.1:46101/alc/collection1&sort=n_tdt1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 1170745 INFO  (qtp582142779-73104) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_tdt1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170749 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tdt1+asc&shard.url=[ff01::213]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::114]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657885&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170750 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657885&ids=144,1,101,112,113,125,15,118,8,142&isShard=true&shard.url=[ff01::213]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::114]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170751 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::213]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::114]:33332/alc&sort=n_tdt1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 1170753 INFO  (qtp582142779-73097) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=a_i1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170756 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=a_i1+desc&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::114]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657893&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170758 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657893&ids=1,12,2,13,3,5,7,8,9,10&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::114]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170759 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=http://127.0.0.1:46101/alc/collection1|[ff01::114]:33332/alc&sort=a_i1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=4
   [junit4]   2> 1170761 INFO  (qtp582142779-73102) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort={!func}testfunc(add(a_i1,5))+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170765 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort={!func}testfunc(add(a_i1,5))+desc&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc|[ff01::114]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657901&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170767 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657901&ids=1,12,2,13,3,5,7,8,9,10&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc|[ff01::114]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170767 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc|[ff01::114]:33332/alc&sort={!func}testfunc(add(a_i1,5))+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=4
   [junit4]   2> 1170769 INFO  (qtp582142779-73103) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=a_i1+asc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170774 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=a_i1+asc&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::114]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657910&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170776 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657910&ids=11,12,1,13,2,3,4,6,7,9&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::114]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170776 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=http://127.0.0.1:46101/alc/collection1|[ff01::114]:33332/alc&sort=a_i1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=4
   [junit4]   2> 1170779 INFO  (qtp582142779-73104) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&fl=*,score&sort=a_i1+desc&wt=javabin&version=2} 
hits=68 status=0 QTime=1
   [junit4]   2> 1170782 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&sort=a_i1+desc&shard.url=[ff01::114]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657919&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170784 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&fl=*,score&shards.purpose=64&NOW=1475162657919&ids=1,12,2,13,3,5,7,8,9,10&isShard=true&shard.url=[ff01::114]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170785 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::114]:33332/alc|[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc&fl=*,score&sort=a_i1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 1170786 INFO  (qtp582142779-73097) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&fl=*,score&sort=n_tl1+asc&wt=javabin&version=2} 
hits=68 status=0 QTime=0
   [junit4]   2> 1170789 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&sort=n_tl1+asc&shard.url=[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657926&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170791 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&fl=*,score&shards.purpose=64&NOW=1475162657926&ids=143,144,100,3,14,17,127,119,120,142&isShard=true&shard.url=[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170792 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::213]:33332/alc&fl=*,score&sort=n_tl1+asc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 1170793 INFO  (qtp582142779-73102) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&sort=n_tl1+desc&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170797 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&shards.purpose=4&start=0&fsv=true&sort=n_tl1+desc&shard.url=[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::213]:33332/alc&rows=10&version=2&q=*:*&NOW=1475162657934&isShard=true&wt=javabin}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170799 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&distrib=false&shards.purpose=64&NOW=1475162657934&ids=11,133,12,101,102,125,16,138,149,106&isShard=true&shard.url=[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::213]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170800 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=*:*&shards=[ff01::114]:33332/alc|http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::213]:33332/alc&sort=n_tl1+desc&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 1170802 INFO  (qtp582142779-73103) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q={!func}a_i1&distrib=false&wt=javabin&version=2} hits=68 status=0 
QTime=0
   [junit4]   2> 1170805 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q={!func}a_i1&distrib=false&fl=id&fl=score&shards.purpose=4&NOW=1475162657942&start=0&fsv=true&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1&rows=10&wt=javabin&version=2}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170807 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q={!func}a_i1&distrib=false&shards.purpose=64&NOW=1475162657942&ids=1,12,2,13,3,5,7,8,9,10&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170808 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q={!func}a_i1&shards=http://127.0.0.1:46101/alc/collection1&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 1170810 INFO  (qtp582142779-73104) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q={!func}a_i1&distrib=false&fl=*,score&wt=javabin&version=2} hits=68 
status=0 QTime=0
   [junit4]   2> 1170813 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q={!func}a_i1&distrib=false&fl=id&fl=score&shards.purpose=4&NOW=1475162657949&start=0&fsv=true&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc&rows=10&wt=javabin&version=2}
 hits=68 status=0 QTime=0
   [junit4]   2> 1170815 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q={!func}a_i1&distrib=false&fl=*,score&shards.purpose=64&NOW=1475162657949&ids=1,12,2,13,3,5,7,8,9,10&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170815 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q={!func}a_i1&shards=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc&fl=*,score&wt=javabin&version=2}
 hits=68 status=0 QTime=3
   [junit4]   2> 1170818 INFO  (qtp582142779-73097) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=quick&distrib=false&wt=javabin&version=2} hits=2 status=0 QTime=0
   [junit4]   2> 1170821 INFO  (qtp980594094-73114) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=quick&distrib=false&fl=id&fl=score&shards.purpose=4&NOW=1475162657957&start=0&fsv=true&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::213]:33332/alc|[ff01::114]:33332/alc&rows=10&wt=javabin&version=2}
 hits=2 status=0 QTime=0
   [junit4]   2> 1170822 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=quick&distrib=false&shards.purpose=64&NOW=1475162657957&ids=4,5&isShard=true&shard.url=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::213]:33332/alc|[ff01::114]:33332/alc&wt=javabin&version=2}
 status=0 QTime=0
   [junit4]   2> 1170822 INFO  (qtp980594094-73120) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=quick&shards=http://127.0.0.1:46101/alc/collection1|[ff01::083]:33332/alc|[ff01::213]:33332/alc|[ff01::114]:33332/alc&wt=javabin&version=2}
 hits=2 status=0 QTime=3
   [junit4]   2> 1170824 INFO  (qtp582142779-73102) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=all&distrib=false&fl=id&start=0&wt=javabin&version=2} hits=2 status=0 
QTime=0
   [junit4]   2> 1170828 INFO  (qtp980594094-73119) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=all&distrib=false&fl=id&fl=score&shards.purpose=68&NOW=1475162657964&start=0&fsv=true&isShard=true&shard.url=[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&rows=10&wt=javabin&version=2}
 hits=2 status=0 QTime=0
   [junit4]   2> 1170829 INFO  (qtp980594094-73115) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=all&shards=[ff01::083]:33332/alc|http://127.0.0.1:46101/alc/collection1&fl=id&start=0&wt=javabin&version=2}
 hits=2 status=0 QTime=2
   [junit4]   2> 1170830 INFO  (qtp582142779-73103) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={q=all&distrib=false&fl=foofoofoo&start=0&wt=javabin&version=2} hits=2 
status=0 QTime=0
   [junit4]   2> 1170833 INFO  (qtp980594094-73121) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select params={q=all&dist

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

O+50]&q=*:*&shards=[ff01::213]:33332/alc|[ff01::083]:33332/alc|[ff01::114]:33332/alc|http://127.0.0.1:34306/alc/collection1,[ff01::114]:33332/alc|http://127.0.0.1:44648/alc/collection1&shards.tolerant=true&shards.info=true&facet=true&wt=javabin&version=2}
 hits=70 status=0 QTime=5
   [junit4]   2> 1233846 WARN  (qtp469710639-73144) [    ] 
o.a.s.h.c.SearchHandler Query: 
distrib=false&fl=id,a_i1&group.limit=10&sort=a_i1+asc,+id+asc&shards.info=true&rows=100&group.query=a_t:kings+OR+a_t:eggs&version=2&q=*:*&shards.tolerant=true&timeAllowed=1&wt=javabin&group=true;
 The request took too long to iterate over terms. Timeout: timeoutAt: 
2081891018029927 (System.nanoTime(): 2081891019746674), 
TermsEnum=org.apache.lucene.codecs.blocktree.SegmentTermsEnum@6c284c23
   [junit4]   2> 1233846 INFO  (qtp469710639-73144) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id,a_i1&group.limit=10&sort=a_i1+asc,+id+asc&shards.info=true&rows=100&group.query=a_t:kings+OR+a_t:eggs&version=2&q=*:*&shards.tolerant=true&timeAllowed=1&wt=javabin&group=true}
 status=0 QTime=3
   [junit4]   2> 1233853 WARN  (qtp1571787440-73160) [    ] 
o.a.s.h.c.SearchHandler Query: 
distrib=false&fl=id&group.limit=10&shards.purpose=4&start=0&sort=a_i1+asc,+id+asc&shards.info=true&shard.url=http://127.0.0.1:34306/alc/collection1&rows=100&group.query=a_t:kings+OR+a_t:eggs&version=2&group.distributed.second=true&q=*:*&shards.tolerant=true&NOW=1475162720986&isShard=true&timeAllowed=1&wt=javabin&group=true;
 The request took too long to iterate over terms. Timeout: timeoutAt: 
2081891026547161 (System.nanoTime(): 2081891027280833), 
TermsEnum=org.apache.lucene.codecs.blocktree.SegmentTermsEnum@79f639c2
   [junit4]   2> 1233854 INFO  (qtp1571787440-73160) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={distrib=false&fl=id&group.limit=10&shards.purpose=4&start=0&sort=a_i1+asc,+id+asc&shards.info=true&shard.url=http://127.0.0.1:34306/alc/collection1&rows=100&group.query=a_t:kings+OR+a_t:eggs&version=2&group.distributed.second=true&q=*:*&shards.tolerant=true&NOW=1475162720986&isShard=true&timeAllowed=1&wt=javabin&group=true}
 status=0 QTime=2
   [junit4]   2> 1233864 INFO  (qtp1571787440-73155) [    ] o.a.s.c.S.Request 
[collection1]  webapp=/alc path=/select 
params={fl=id,a_i1&group.limit=10&sort=a_i1+asc,+id+asc&shards.info=true&rows=100&group.query=a_t:kings+OR+a_t:eggs&version=2&q=*:*&shards=http://127.0.0.1:34306/alc/collection1,[ff01::083]:33332/alc|[ff01::114]:33332/alc|http://127.0.0.1:44648/alc/collection1&shards.tolerant=true&timeAllowed=1&wt=javabin&group=true}
 status=0 QTime=16
   [junit4]   2> 1233866 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.SolrTestCaseJ4 ###Ending test
   [junit4]   2> 1233867 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.e.j.s.ServerConnector Stopped 
ServerConnector@47d37585{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 1233868 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=1320148071
   [junit4]   2> 1233868 INFO  (coreCloseExecutor-7043-thread-1) [    ] 
o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@49acba5e
   [junit4]   2> 1233879 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@7f78976b{/alc,null,UNAVAILABLE}
   [junit4]   2> 1233880 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.e.j.s.ServerConnector Stopped 
ServerConnector@1a79c167{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 1233881 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=841448955
   [junit4]   2> 1233881 INFO  (coreCloseExecutor-7045-thread-1) [    ] 
o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@79a8d301
   [junit4]   2> 1233890 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@30858d6f{/alc,null,UNAVAILABLE}
   [junit4]   2> 1233892 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.e.j.s.ServerConnector Stopped 
ServerConnector@124a16a0{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
   [junit4]   2> 1233892 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=2107362779
   [junit4]   2> 1233892 INFO  (coreCloseExecutor-7047-thread-1) [    ] 
o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@166eb23d
   [junit4]   2> 1233905 INFO  
(TEST-TestDistributedSearch.test-seed#[73E86667E3AB2998]) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@433caa2f{/alc,null,UNAVAILABLE}
   [junit4]   2> NOTE: reproduce with: ant test  
-Dtestcase=TestDistributedSearch -Dtests.method=test 
-Dtests.seed=73E86667E3AB2998 -Dtests.multiplier=3 -Dtests.slow=true 
-Dtests.locale=kw -Dtests.timezone=Africa/Maseru -Dtests.asserts=true 
-Dtests.file.encoding=UTF-8
   [junit4] FAILURE 64.7s J2 | TestDistributedSearch.test <<<
   [junit4]    > Throwable #1: java.lang.AssertionError: Expected to find 
shardAddress in the up shard info
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([73E86667E3AB2998:FBBC59BD4D574460]:0)
   [junit4]    >        at 
org.apache.solr.TestDistributedSearch.comparePartialResponses(TestDistributedSearch.java:1162)
   [junit4]    >        at 
org.apache.solr.TestDistributedSearch.queryPartialResults(TestDistributedSearch.java:1103)
   [junit4]    >        at 
org.apache.solr.TestDistributedSearch.test(TestDistributedSearch.java:963)
   [junit4]    >        at 
jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@9-ea/Native 
Method)
   [junit4]    >        at 
jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@9-ea/NativeMethodAccessorImpl.java:62)
   [junit4]    >        at 
jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@9-ea/DelegatingMethodAccessorImpl.java:43)
   [junit4]    >        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsRepeatStatement.callStatement(BaseDistributedSearchTestCase.java:1018)
   [junit4]    >        at 
org.apache.solr.BaseDistributedSearchTestCase$ShardsRepeatRule$ShardsStatement.evaluate(BaseDistributedSearchTestCase.java:967)
   [junit4]    >        at java.lang.Thread.run(java.base@9-ea/Thread.java:843)
   [junit4]   2> 1233908 INFO  
(SUITE-TestDistributedSearch-seed#[73E86667E3AB2998]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> NOTE: leaving temporary files on disk at: 
/home/jenkins/workspace/Lucene-Solr-6.x-Linux/solr/build/solr-core/test/J2/temp/solr.TestDistributedSearch_73E86667E3AB2998-001
   [junit4]   2> NOTE: test params are: 
codec=DummyCompressingStoredFields(storedFieldsFormat=CompressingStoredFieldsFormat(compressionMode=DUMMY,
 chunkSize=2, maxDocsPerChunk=7, blockSize=10), 
termVectorsFormat=CompressingTermVectorsFormat(compressionMode=DUMMY, 
chunkSize=2, blockSize=10)), sim=RandomSimilarity(queryNorm=true,coord=no): {}, 
locale=kw, timezone=Africa/Maseru
   [junit4]   2> NOTE: Linux 4.4.0-36-generic amd64/Oracle Corporation 9-ea 
(64-bit)/cpus=12,threads=1,free=173147264,total=518979584
   [junit4]   2> NOTE: All tests run in this JVM: [TestMacroExpander, 
TestDownShardTolerantSearch, TestSolrDeletionPolicy1, TestStandardQParsers, 
HdfsDirectoryFactoryTest, TestHighFrequencyDictionaryFactory, 
TestStressLiveNodes, BasicAuthIntegrationTest, RollingRestartTest, 
TestZkChroot, TestBinaryField, BadCopyFieldTest, TestRawTransformer, 
SuggesterWFSTTest, TestXIncludeConfig, TestXmlQParser, TestChildDocTransformer, 
TermVectorComponentDistributedTest, DirectUpdateHandlerOptimizeTest, 
TestCopyFieldCollectionResource, TestCollectionAPI, DebugComponentTest, 
TestGeoJSONResponseWriter, FullSolrCloudDistribCmdsTest, HardAutoCommitTest, 
TestSolrJ, OpenExchangeRatesOrgProviderTest, TestLocalFSCloudBackupRestore, 
DistributedFacetPivotLongTailTest, DocValuesMultiTest, TestMergePolicyConfig, 
TestFieldCacheSanityChecker, TestConfigSetsAPIZkFailure, RequestLoggingTest, 
TestCloudInspectUtil, BasicDistributedZk2Test, CoreSorterTest, 
TestUseDocValuesAsStored, TestExpandComponent, TestFieldTypeCollectionResource, 
RecoveryZkTest, MinimalSchemaTest, TestCollationField, 
CollectionsAPIAsyncDistributedZkTest, TestNonDefinedSimilarityFactory, 
DateRangeFieldTest, TestOverriddenPrefixQueryForCustomFieldType, 
SimpleMLTQParserTest, SolrXmlInZkTest, TestConfigSets, DataDrivenBlockJoinTest, 
TestWriterPerf, TestDFRSimilarityFactory, TestSolrDynamicMBean, 
ResponseLogComponentTest, ReplaceNodeTest, TestJettySolrRunner, 
UUIDUpdateProcessorFallbackTest, TestUniqueKeyFieldResource, 
TestDynamicFieldResource, TestPostingsSolrHighlighter, TestScoreJoinQPScore, 
TestLMJelinekMercerSimilarityFactory, AutoCommitTest, SOLR749Test, 
DocExpirationUpdateProcessorFactoryTest, HdfsBasicDistributedZk2Test, 
PingRequestHandlerTest, SpellPossibilityIteratorTest, BlockJoinFacetSimpleTest, 
TestJmxMonitoredMap, TestAnalyzedSuggestions, SpatialRPTFieldTypeTest, 
TestSolrCloudWithDelegationTokens, TestLeaderElectionWithEmptyReplica, 
TestRandomFlRTGCloud, DistribJoinFromCollectionTest, 
PreAnalyzedUpdateProcessorTest, SuggesterTest, CdcrReplicationHandlerTest, 
SolrPluginUtilsTest, NoCacheHeaderTest, 
StatelessScriptUpdateProcessorFactoryTest, JavabinLoaderTest, 
TestHdfsBackupRestoreCore, TestExtendedDismaxParser, HdfsRecoverLeaseTest, 
TestRestoreCore, BadIndexSchemaTest, TestRestManager, 
SolrCoreCheckLockOnStartupTest, TestCustomSort, TestConfig, TestReload, 
SmileWriterTest, BJQParserTest, CollectionReloadTest, TestReloadDeadlock, 
AddBlockUpdateTest, BasicDistributedZkTest, ChaosMonkeySafeLeaderTest, 
UnloadDistributedZkTest, CollectionsAPIDistributedZkTest, TestDistributedSearch]
   [junit4] Completed [320/636 (1!)] on J2 in 64.76s, 1 test, 1 failure <<< 
FAILURES!

[...truncated 50865 lines...]


---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]

Reply via email to