[JENKINS-EA] Lucene-Solr-7.0-Windows (64bit/jdk-9-ea+178) - Build # 39 - Still Unstable!

[Policeman Jenkins Server]

Build: https://jenkins.thetaphi.de/job/Lucene-Solr-7.0-Windows/39/
Java: 64bit/jdk-9-ea+178 -XX:+UseCompressedOops -XX:+UseParallelGC 
--illegal-access=deny

1 tests failed.
FAILED:  
junit.framework.TestSuite.org.apache.solr.schema.TestUseDocValuesAsStored

Error Message:
Could not remove the following files (in the order of attempts):    
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\init-core-data-001:
 java.nio.file.AccessDeniedException: 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\init-core-data-001
    
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001:
 java.nio.file.DirectoryNotEmptyException: 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001
 

Stack Trace:
java.io.IOException: Could not remove the following files (in the order of 
attempts):
   
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\init-core-data-001:
 java.nio.file.AccessDeniedException: 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\init-core-data-001
   
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001:
 java.nio.file.DirectoryNotEmptyException: 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001

        at __randomizedtesting.SeedInfo.seed([DA2919536188098E]:0)
        at org.apache.lucene.util.IOUtils.rm(IOUtils.java:329)
        at 
org.apache.lucene.util.TestRuleTemporaryFilesCleanup.afterAlways(TestRuleTemporaryFilesCleanup.java:216)
        at 
com.carrotsearch.randomizedtesting.rules.TestRuleAdapter$1.afterAlways(TestRuleAdapter.java:31)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
        at 
org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
        at 
org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
        at 
org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
        at 
com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
        at 
com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
        at java.base/java.lang.Thread.run(Thread.java:844)




Build Log:
[...truncated 12984 lines...]
   [junit4] Suite: org.apache.solr.schema.TestUseDocValuesAsStored
   [junit4]   2> Creating dataDir: 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\init-core-data-001
   [junit4]   2> 2732949 WARN  
(SUITE-TestUseDocValuesAsStored-seed#[DA2919536188098E]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=3 numCloses=3
   [junit4]   2> 2732949 INFO  
(SUITE-TestUseDocValuesAsStored-seed#[DA2919536188098E]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) 
w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 2732951 INFO  
(SUITE-TestUseDocValuesAsStored-seed#[DA2919536188098E]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (true) via: 
@org.apache.solr.util.RandomizeSSL(reason="", value=0.0/0.0, ssl=0.0/0.0, 
clientAuth=0.0/0.0)
   [junit4]   2> 2732952 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.SolrTestCaseJ4 ###Starting testMultivaluedOrdering
   [junit4]   2> 2732974 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 2732982 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2732986 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, 
but managed schema resource managed-schema not found - loading non-managed 
schema schema-non-stored-docvalues.xml instead
   [junit4]   2> 2732989 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.s.IndexSchema [null] Schema name=test-non-stored-docvalues
   [junit4]   2> 2732994 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.s.IndexSchema Loaded schema test-non-stored-docvalues/1.6 with 
uniqueid field id
   [junit4]   2> 2732994 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.s.ManagedIndexSchema Upgraded to managed schema at 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-001\collection1\conf\managed-schema
   [junit4]   2> 2733002 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema, 
renamed the non-managed schema 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-001\collection1\conf\schema-non-stored-docvalues.xml
 to 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-001\collection1\conf\schema-non-stored-docvalues.xml.bak
   [junit4]   2> 2733037 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 
'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733040 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 
'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733041 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733087 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2733093 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] Schema name=test-non-stored-docvalues
   [junit4]   2> 2733097 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.s.IndexSchema Loaded schema test-non-stored-docvalues/1.6 with uniqueid 
field id
   [junit4]   2> 2733098 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
instancedir 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-001\collection1,
 trusted=true
   [junit4]   2> 2733098 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 
'solr.core.collection1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733098 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 2733098 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-001\collection1],
 
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\init-core-data-001\]
   [junit4]   2> 2733104 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=24, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=69.9287109375, 
floorSegmentMB=0.3984375, forceMergeDeletesPctAllowed=7.392364011028762, 
segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 2733108 WARN  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,attributes = 
{initParams=a, name=/dump, registerPath=/solr,/v2, 
class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
   [junit4]   2> 2733175 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2733176 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2733176 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=21, maxMergeAtOnceExplicit=29, maxMergedSegmentMB=42.0048828125, 
floorSegmentMB=0.8876953125, forceMergeDeletesPctAllowed=6.172742899051549, 
segmentsPerTier=11.0, maxCFSSegmentSizeMB=8.796093022207999E12, 
noCFSRatio=0.2662050097373171
   [junit4]   2> 2733177 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@1eb748fa[collection1] main]
   [junit4]   2> 2733177 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-001\collection1\conf
   [junit4]   2> 2733178 INFO  (coreLoadExecutor-10514-thread-1) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2733180 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 2733180 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM 
INDEX
   [junit4]   2> 2733181 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*}
 0 0
   [junit4]   2> 2733181 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[1]} 0 0
   [junit4]   2> 2733183 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[2]} 0 0
   [junit4]   2> 2733183 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[3]} 0 0
   [junit4]   2> 2733183 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[4]} 0 0
   [junit4]   2> 2733183 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733183 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@26e648b5 commitCommandVersion:0
   [junit4]   2> 2733192 INFO  (searcherExecutor-10515-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@1eb748fa[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2733200 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@288050a9[collection1] main]
   [junit4]   2> 2733202 INFO  (searcherExecutor-10515-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@288050a9[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):c4)))}
   [junit4]   2> 2733202 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733202 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{commit=} 0 19
   [junit4]   2> 2733203 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:1&fl=test_mvt_dvt_st_str&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733203 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:2&fl=test_mvt_dvt_sf_str&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733204 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:3&fl=test_mvt_dvf_st_str&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733204 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:4&fl=test_mvt_dvu_st_str&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733205 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM 
INDEX
   [junit4]   2> 2733205 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*}
 0 0
   [junit4]   2> 2733205 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733205 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@26e648b5 commitCommandVersion:0
   [junit4]   2> 2733209 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@33babc51[collection1] main]
   [junit4]   2> 2733209 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733211 INFO  (searcherExecutor-10515-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@33babc51[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2733216 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{commit=} 0 10
   [junit4]   2> 2733216 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 2733216 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1383360338
   [junit4]   2> 2733216 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.node, tag=null
   [junit4]   2> 2733217 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.jvm, tag=null
   [junit4]   2> 2733218 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.jetty, tag=null
   [junit4]   2> 2733219 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 2733222 INFO  (coreCloseExecutor-10519-thread-1) [    ] 
o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@53122b75
   [junit4]   2> 2733224 INFO  (coreCloseExecutor-10519-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.collection1, tag=1393699701
   [junit4]   2> 2733227 INFO  
(TEST-TestUseDocValuesAsStored.testMultivaluedOrdering-seed#[DA2919536188098E]) 
[    ] o.a.s.SolrTestCaseJ4 ###Ending testMultivaluedOrdering
   [junit4]   2> 2733229 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testDuplicateMultiValued
   [junit4]   2> 2733237 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 2733252 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2733255 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, 
but managed schema resource managed-schema not found - loading non-managed 
schema schema-non-stored-docvalues.xml instead
   [junit4]   2> 2733258 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.IndexSchema [null] Schema name=test-non-stored-docvalues
   [junit4]   2> 2733262 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.IndexSchema Loaded schema test-non-stored-docvalues/1.6 with 
uniqueid field id
   [junit4]   2> 2733262 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.ManagedIndexSchema Upgraded to managed schema at 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-002\collection1\conf\managed-schema
   [junit4]   2> 2733264 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema, 
renamed the non-managed schema 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-002\collection1\conf\schema-non-stored-docvalues.xml
 to 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-002\collection1\conf\schema-non-stored-docvalues.xml.bak
   [junit4]   2> 2733296 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 
'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733299 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 
'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733299 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733305 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2733311 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] Schema name=test-non-stored-docvalues
   [junit4]   2> 2733314 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.s.IndexSchema Loaded schema test-non-stored-docvalues/1.6 with uniqueid 
field id
   [junit4]   2> 2733314 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
instancedir 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-002\collection1,
 trusted=true
   [junit4]   2> 2733314 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 
'solr.core.collection1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733314 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 2733314 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-002\collection1],
 
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\init-core-data-001\]
   [junit4]   2> 2733319 WARN  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,attributes = 
{initParams=a, name=/dump, registerPath=/solr,/v2, 
class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
   [junit4]   2> 2733359 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2733359 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2733361 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=24, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=69.9287109375, 
floorSegmentMB=0.3984375, forceMergeDeletesPctAllowed=7.392364011028762, 
segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 2733361 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@75ff1276[collection1] main]
   [junit4]   2> 2733362 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-002\collection1\conf
   [junit4]   2> 2733362 INFO  (coreLoadExecutor-10526-thread-1) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2733362 INFO  (searcherExecutor-10527-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@75ff1276[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2733363 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 2733364 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[1]} 0 0
   [junit4]   2> 2733364 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733364 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5f2bc28e commitCommandVersion:0
   [junit4]   2> 2733371 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@1b2860cc[collection1] main]
   [junit4]   2> 2733371 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733371 INFO  (searcherExecutor-10527-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@1b2860cc[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.0.0):c1)))}
   [junit4]   2> 2733371 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 7
   [junit4]   2> 2733372 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:1&fl=test_ss_dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733372 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:1&fl=test_ss_dvo,*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733373 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:1&fl=*dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733373 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:1&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733374 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:1&fl=test_ss_dvo,fakeFieldName&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733374 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733374 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[2]} 0 0
   [junit4]   2> 2733375 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733375 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5f2bc28e commitCommandVersion:0
   [junit4]   2> 2733381 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@c80bb23[collection1] main]
   [junit4]   2> 2733381 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733381 INFO  (searcherExecutor-10527-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@c80bb23[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.0.0):c1)
 Uninverting(_2(7.0.0):c1)))}
   [junit4]   2> 2733381 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 7
   [junit4]   2> 2733383 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:2&fl=test_ss_dv&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733383 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:2&fl=test_ss_dv,*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733383 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:2&fl=*_dv&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733384 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:2&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733384 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:2&fl=test_ss_dv,fakeFieldName&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733384 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=2 status=0 QTime=0
   [junit4]   2> 2733385 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[3]} 0 0
   [junit4]   2> 2733385 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733385 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5f2bc28e commitCommandVersion:0
   [junit4]   2> 2733392 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@3e076494[collection1] main]
   [junit4]   2> 2733393 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733393 INFO  (searcherExecutor-10527-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@3e076494[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.0.0):c1)
 Uninverting(_2(7.0.0):c1) Uninverting(_3(7.0.0):c1)))}
   [junit4]   2> 2733393 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 7
   [junit4]   2> 2733393 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:3&fl=test_ss_dvo2&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733394 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:3&fl=test_ss_dvo2,*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733394 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:3&fl=*vo2&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733394 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:3&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733394 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:3&fl=test_ss_dvo2,fakeFieldName&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733395 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=3 status=0 QTime=0
   [junit4]   2> 2733397 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[4]} 0 0
   [junit4]   2> 2733397 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733397 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5f2bc28e commitCommandVersion:0
   [junit4]   2> 2733403 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@58412931[collection1] main]
   [junit4]   2> 2733404 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733404 INFO  (searcherExecutor-10527-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@58412931[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.0.0):c1)
 Uninverting(_2(7.0.0):c1) Uninverting(_3(7.0.0):c1) 
Uninverting(_4(7.0.0):c1)))}
   [junit4]   2> 2733404 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 8
   [junit4]   2> 2733406 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:4&fl=test_is_dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733406 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:4&fl=test_is_dvo,*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733407 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:4&fl=*dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733407 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:4&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733407 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:4&fl=test_is_dvo,fakeFieldName&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733407 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=4 status=0 QTime=0
   [junit4]   2> 2733413 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[5]} 0 0
   [junit4]   2> 2733414 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733414 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5f2bc28e commitCommandVersion:0
   [junit4]   2> 2733422 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@a30c4a8[collection1] main]
   [junit4]   2> 2733422 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733423 INFO  (searcherExecutor-10527-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@a30c4a8[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.0.0):c1)
 Uninverting(_2(7.0.0):c1) Uninverting(_3(7.0.0):c1) Uninverting(_4(7.0.0):c1) 
Uninverting(_5(7.0.0):c1)))}
   [junit4]   2> 2733423 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 9
   [junit4]   2> 2733423 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:5&fl=test_fs_dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733424 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:5&fl=test_fs_dvo,*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733424 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:5&fl=*dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733424 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:5&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733425 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:5&fl=test_fs_dvo,fakeFieldName&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733425 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=5 status=0 QTime=0
   [junit4]   2> 2733426 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[6]} 0 0
   [junit4]   2> 2733426 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733426 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5f2bc28e commitCommandVersion:0
   [junit4]   2> 2733434 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@2d00374c[collection1] main]
   [junit4]   2> 2733434 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733435 INFO  (searcherExecutor-10527-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@2d00374c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.0.0):c1)
 Uninverting(_2(7.0.0):c1) Uninverting(_3(7.0.0):c1) Uninverting(_4(7.0.0):c1) 
Uninverting(_5(7.0.0):c1) Uninverting(_6(7.0.0):c1)))}
   [junit4]   2> 2733435 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 9
   [junit4]   2> 2733435 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:6&fl=test_ls_dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733436 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:6&fl=test_ls_dvo,*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733436 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:6&fl=*dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733436 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:6&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733437 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:6&fl=test_ls_dvo,fakeFieldName&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733437 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=6 status=0 QTime=0
   [junit4]   2> 2733438 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[7]} 0 0
   [junit4]   2> 2733438 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733438 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5f2bc28e commitCommandVersion:0
   [junit4]   2> 2733448 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@55bee65d[collection1] main]
   [junit4]   2> 2733448 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733449 INFO  (searcherExecutor-10527-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@55bee65d[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.0.0):c1)
 Uninverting(_2(7.0.0):c1) Uninverting(_3(7.0.0):c1) Uninverting(_4(7.0.0):c1) 
Uninverting(_5(7.0.0):c1) Uninverting(_6(7.0.0):c1) Uninverting(_7(7.0.0):c1)))}
   [junit4]   2> 2733449 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 10
   [junit4]   2> 2733449 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:7&fl=test_ds_dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733450 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:7&fl=test_ds_dvo,*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733450 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:7&fl=*dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733450 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:7&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733451 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:7&fl=test_ds_dvo,fakeFieldName&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733451 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=7 status=0 QTime=0
   [junit4]   2> 2733453 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[8]} 0 0
   [junit4]   2> 2733453 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733453 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5f2bc28e commitCommandVersion:0
   [junit4]   2> 2733462 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@a18e537[collection1] main]
   [junit4]   2> 2733463 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733463 INFO  (searcherExecutor-10527-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@a18e537[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.0.0):c1)
 Uninverting(_2(7.0.0):c1) Uninverting(_3(7.0.0):c1) Uninverting(_4(7.0.0):c1) 
Uninverting(_5(7.0.0):c1) Uninverting(_6(7.0.0):c1) Uninverting(_7(7.0.0):c1) 
Uninverting(_8(7.0.0):c1)))}
   [junit4]   2> 2733463 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 10
   [junit4]   2> 2733463 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:8&fl=test_dts_dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733464 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:8&fl=test_dts_dvo,*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733464 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:8&fl=*dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733464 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:8&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733464 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:8&fl=test_dts_dvo,fakeFieldName&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733465 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=8 status=0 QTime=0
   [junit4]   2> 2733466 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[9]} 0 0
   [junit4]   2> 2733466 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733466 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5f2bc28e commitCommandVersion:0
   [junit4]   2> 2733475 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6693b2ea[collection1] main]
   [junit4]   2> 2733476 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733476 INFO  (searcherExecutor-10527-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@6693b2ea[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.0.0):c1)
 Uninverting(_2(7.0.0):c1) Uninverting(_3(7.0.0):c1) Uninverting(_4(7.0.0):c1) 
Uninverting(_5(7.0.0):c1) Uninverting(_6(7.0.0):c1) Uninverting(_7(7.0.0):c1) 
Uninverting(_8(7.0.0):c1) Uninverting(_9(7.0.0):c1)))}
   [junit4]   2> 2733476 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 10
   [junit4]   2> 2733476 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:9&fl=enums_dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733478 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:9&fl=enums_dvo,*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733479 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:9&fl=*dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733479 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:9&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733479 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:9&fl=enums_dvo,fakeFieldName&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733480 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=9 status=0 QTime=0
   [junit4]   2> 2733480 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM 
INDEX
   [junit4]   2> 2733480 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null 
params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*}
 0 0
   [junit4]   2> 2733480 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733480 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5f2bc28e commitCommandVersion:0
   [junit4]   2> 2733482 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@13819db4[collection1] main]
   [junit4]   2> 2733483 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733483 INFO  (searcherExecutor-10527-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@13819db4[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2733487 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 6
   [junit4]   2> 2733487 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 2733487 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=850120906
   [junit4]   2> 2733487 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.node, tag=null
   [junit4]   2> 2733488 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.jvm, tag=null
   [junit4]   2> 2733489 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.jetty, tag=null
   [junit4]   2> 2733489 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 2733490 INFO  (coreCloseExecutor-10531-thread-1) [    ] 
o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@2cb164e5
   [junit4]   2> 2733491 INFO  (coreCloseExecutor-10531-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.collection1, tag=749823205
   [junit4]   2> 2733493 INFO  
(TEST-TestUseDocValuesAsStored.testDuplicateMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testDuplicateMultiValued
   [junit4]   2> 2733494 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.SolrTestCaseJ4 ###Starting testOnEmptyIndex
   [junit4]   2> 2733502 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 2733507 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2733510 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, but 
managed schema resource managed-schema not found - loading non-managed schema 
schema-non-stored-docvalues.xml instead
   [junit4]   2> 2733511 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.s.IndexSchema [null] Schema name=test-non-stored-docvalues
   [junit4]   2> 2733516 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.s.IndexSchema Loaded schema test-non-stored-docvalues/1.6 with uniqueid 
field id
   [junit4]   2> 2733516 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.s.ManagedIndexSchema Upgraded to managed schema at 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-003\collection1\conf\managed-schema
   [junit4]   2> 2733519 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema, renamed 
the non-managed schema 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-003\collection1\conf\schema-non-stored-docvalues.xml
 to 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-003\collection1\conf\schema-non-stored-docvalues.xml.bak
   [junit4]   2> 2733550 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') 
enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733553 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') 
enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733553 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733560 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2733565 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] Schema name=test-non-stored-docvalues
   [junit4]   2> 2733574 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.s.IndexSchema Loaded schema test-non-stored-docvalues/1.6 with uniqueid 
field id
   [junit4]   2> 2733574 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
instancedir 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-003\collection1,
 trusted=true
   [junit4]   2> 2733574 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 
'solr.core.collection1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733575 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 2733575 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-003\collection1],
 
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\init-core-data-001\]
   [junit4]   2> 2733579 WARN  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,attributes = 
{initParams=a, name=/dump, registerPath=/solr,/v2, 
class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
   [junit4]   2> 2733622 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2733622 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2733623 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=24, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=69.9287109375, 
floorSegmentMB=0.3984375, forceMergeDeletesPctAllowed=7.392364011028762, 
segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 2733623 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@7eafa74a[collection1] main]
   [junit4]   2> 2733623 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-003\collection1\conf
   [junit4]   2> 2733624 INFO  (coreLoadExecutor-10538-thread-1) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2733624 INFO  (searcherExecutor-10539-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@7eafa74a[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2733625 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 2733625 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 2733625 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*}
 0 0
   [junit4]   2> 2733625 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733625 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@70aafb4d commitCommandVersion:0
   [junit4]   2> 2733628 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@4babf5ba[collection1] main]
   [junit4]   2> 2733628 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733629 INFO  (searcherExecutor-10539-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@4babf5ba[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2733629 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{commit=} 0 3
   [junit4]   2> 2733629 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} 
hits=0 status=0 QTime=0
   [junit4]   2> 2733629 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 2733629 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=test_nonstored_dv_str&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 2733629 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*,test_nonstored_dv_str&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 2733630 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[xyz]} 0 0
   [junit4]   2> 2733630 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} 
hits=0 status=0 QTime=0
   [junit4]   2> 2733630 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 2733630 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=test_nonstored_dv_str&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 2733630 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*,test_nonstored_dv_str&wt=xml} hits=0 status=0 QTime=0
   [junit4]   2> 2733630 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733630 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@70aafb4d commitCommandVersion:0
   [junit4]   2> 2733636 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@32b03a7f[collection1] main]
   [junit4]   2> 2733636 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733638 INFO  (searcherExecutor-10539-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@32b03a7f[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_a(7.0.0):c1)))}
   [junit4]   2> 2733638 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{commit=} 0 7
   [junit4]   2> 2733638 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} 
hits=1 status=0 QTime=0
   [junit4]   2> 2733639 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733639 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=test_nonstored_dv_str&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733639 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*,test_nonstored_dv_str&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733639 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{add=[xyz]} 0 0
   [junit4]   2> 2733640 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733640 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@70aafb4d commitCommandVersion:0
   [junit4]   2> 2733645 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@104d6f5c[collection1] main]
   [junit4]   2> 2733645 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733646 INFO  (searcherExecutor-10539-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@104d6f5c[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_b(7.0.0):c1)))}
   [junit4]   2> 2733647 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{commit=} 0 6
   [junit4]   2> 2733647 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.S.Request [collection1]  webapp=null path=null params={q=*:*&wt=xml} 
hits=1 status=0 QTime=0
   [junit4]   2> 2733647 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM INDEX
   [junit4]   2> 2733647 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*}
 0 0
   [junit4]   2> 2733647 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733647 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@70aafb4d commitCommandVersion:0
   [junit4]   2> 2733649 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@5aae6b2[collection1] main]
   [junit4]   2> 2733649 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733650 INFO  (searcherExecutor-10539-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@5aae6b2[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2733650 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null path=null 
params={}{commit=} 0 3
   [junit4]   2> 2733652 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 2733652 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.CoreContainer Shutting down CoreContainer instance=646784027
   [junit4]   2> 2733652 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.node, 
tag=null
   [junit4]   2> 2733653 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jvm, 
tag=null
   [junit4]   2> 2733654 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for registry=solr.jetty, 
tag=null
   [junit4]   2> 2733654 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 2733654 INFO  (coreCloseExecutor-10543-thread-1) [    ] 
o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@35b8ebc7
   [junit4]   2> 2733655 INFO  (coreCloseExecutor-10543-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.collection1, tag=901311431
   [junit4]   2> 2733657 INFO  
(TEST-TestUseDocValuesAsStored.testOnEmptyIndex-seed#[DA2919536188098E]) [    ] 
o.a.s.SolrTestCaseJ4 ###Ending testOnEmptyIndex
   [junit4]   2> 2733658 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testRandomSingleAndMultiValued
   [junit4]   2> 2733665 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 2733671 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2733674 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.ManagedIndexSchemaFactory The schema is configured as managed, 
but managed schema resource managed-schema not found - loading non-managed 
schema schema-non-stored-docvalues.xml instead
   [junit4]   2> 2733677 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.IndexSchema [null] Schema name=test-non-stored-docvalues
   [junit4]   2> 2733680 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.IndexSchema Loaded schema test-non-stored-docvalues/1.6 with 
uniqueid field id
   [junit4]   2> 2733681 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.ManagedIndexSchema Upgraded to managed schema at 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-004\collection1\conf\managed-schema
   [junit4]   2> 2733681 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.ManagedIndexSchemaFactory After upgrading to managed schema, 
renamed the non-managed schema 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-004\collection1\conf\schema-non-stored-docvalues.xml
 to 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-004\collection1\conf\schema-non-stored-docvalues.xml.bak
   [junit4]   2> 2733711 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 
'solr.node') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733715 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 
'solr.jvm') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733715 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733722 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.0.0
   [junit4]   2> 2733727 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.s.IndexSchema [collection1] Schema name=test-non-stored-docvalues
   [junit4]   2> 2733730 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.s.IndexSchema Loaded schema test-non-stored-docvalues/1.6 with uniqueid 
field id
   [junit4]   2> 2733730 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.c.CoreContainer Creating SolrCore 'collection1' using configuration from 
instancedir 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-004\collection1,
 trusted=true
   [junit4]   2> 2733730 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.core.collection1' (registry 
'solr.core.collection1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@5529561b
   [junit4]   2> 2733730 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 2733730 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-004\collection1],
 
dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\init-core-data-001\]
   [junit4]   2> 2733735 WARN  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.c.RequestHandlers INVALID paramSet a in requestHandler {type = 
requestHandler,name = /dump,class = DumpRequestHandler,attributes = 
{initParams=a, name=/dump, registerPath=/solr,/v2, 
class=DumpRequestHandler},args = {defaults={a=A,b=B}}}
   [junit4]   2> 2733784 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.u.CommitTracker Hard AutoCommit: disabled
   [junit4]   2> 2733784 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 2733785 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class 
org.apache.lucene.index.TieredMergePolicy: [TieredMergePolicy: 
maxMergeAtOnce=24, maxMergeAtOnceExplicit=50, maxMergedSegmentMB=69.9287109375, 
floorSegmentMB=0.3984375, forceMergeDeletesPctAllowed=7.392364011028762, 
segmentsPerTier=50.0, maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=1.0
   [junit4]   2> 2733786 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@64abb21f[collection1] main]
   [junit4]   2> 2733786 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.r.ManagedResourceStorage File-based storage initialized to use dir: 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\tempDir-004\collection1\conf
   [junit4]   2> 2733787 INFO  (coreLoadExecutor-10550-thread-1) [    ] 
o.a.s.h.ReplicationHandler Commits will be reserved for  10000
   [junit4]   2> 2733787 INFO  (searcherExecutor-10551-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@64abb21f[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 2733788 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 2733789 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 [collection1] REMOVING ALL DOCUMENTS FROM 
INDEX
   [junit4]   2> 2733789 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null 
params={_version_=-9223372036854775807&update.distrib=FROMLEADER&versions=true&wt=json&indent=true}{deleteByQuery=*:*}
 0 0
   [junit4]   2> 2733789 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[1]} 0 0
   [junit4]   2> 2733790 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733790 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5acb185b commitCommandVersion:0
   [junit4]   2> 2733795 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@53a77586[collection1] main]
   [junit4]   2> 2733796 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733796 INFO  (searcherExecutor-10551-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@53a77586[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_c(7.0.0):c1)))}
   [junit4]   2> 2733796 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 7
   [junit4]   2> 2733797 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:1&fl=test_ss_dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733797 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:1&fl=test_ss_dvo,*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733798 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:1&fl=*dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733798 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:1&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733799 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:1&fl=test_ss_dvo,fakeFieldName&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733799 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733800 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[2]} 0 0
   [junit4]   2> 2733800 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733800 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5acb185b commitCommandVersion:0
   [junit4]   2> 2733806 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@5b361114[collection1] main]
   [junit4]   2> 2733808 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733808 INFO  (searcherExecutor-10551-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@5b361114[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_c(7.0.0):c1)
 Uninverting(_d(7.0.0):c1)))}
   [junit4]   2> 2733808 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 7
   [junit4]   2> 2733808 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:2&fl=test_i_dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733809 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:2&fl=test_i_dvo,*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733809 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:2&fl=*dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733809 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:2&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733809 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:2&fl=test_i_dvo,fakeFieldName&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733811 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=2 status=0 QTime=0
   [junit4]   2> 2733811 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[3]} 0 0
   [junit4]   2> 2733811 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 start 
commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 2733811 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@5acb185b commitCommandVersion:0
   [junit4]   2> 2733819 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.s.SolrIndexSearcher Opening [Searcher@6ed0997f[collection1] main]
   [junit4]   2> 2733819 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 2733819 INFO  (searcherExecutor-10551-thread-1) [    ] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@6ed0997f[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_c(7.0.0):c1)
 Uninverting(_d(7.0.0):c1) Uninverting(_e(7.0.0):c1)))}
   [junit4]   2> 2733819 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{commit=} 0 8
   [junit4]   2> 2733820 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:3&fl=test_ds_dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733820 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:3&fl=test_ds_dvo,*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733822 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:3&fl=*dvo&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733822 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:3&fl=*&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733822 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=id:3&fl=test_ds_dvo,fakeFieldName&wt=xml} hits=1 status=0 QTime=0
   [junit4]   2> 2733823 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=*:*&fl=*&wt=xml} hits=3 status=0 QTime=0
   [junit4]   2> 2733824 INFO  
(TEST-TestUseDocValuesAsStored.testRandomSingleAndMultiValued-seed#[DA2919536188098E])
 [    ] o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=null 
path=null params={}{add=[4]

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

 7
   [junit4]   2> 2735569 INFO  
(TEST-TestUseDocValuesAsStored.testMultipleSearchResults-seed#[DA2919536188098E])
 [    ] o.a.s.SolrTestCaseJ4 ###deleteCore
   [junit4]   2> 2735569 INFO  
(TEST-TestUseDocValuesAsStored.testMultipleSearchResults-seed#[DA2919536188098E])
 [    ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=1698555724
   [junit4]   2> 2735569 INFO  
(TEST-TestUseDocValuesAsStored.testMultipleSearchResults-seed#[DA2919536188098E])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.node, tag=null
   [junit4]   2> 2735571 INFO  
(TEST-TestUseDocValuesAsStored.testMultipleSearchResults-seed#[DA2919536188098E])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.jvm, tag=null
   [junit4]   2> 2735572 INFO  
(TEST-TestUseDocValuesAsStored.testMultipleSearchResults-seed#[DA2919536188098E])
 [    ] o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.jetty, tag=null
   [junit4]   2> 2735572 INFO  
(TEST-TestUseDocValuesAsStored.testMultipleSearchResults-seed#[DA2919536188098E])
 [    ] o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 
2147483647 transient cores
   [junit4]   2> 2735572 INFO  (coreCloseExecutor-10591-thread-1) [    ] 
o.a.s.c.SolrCore [collection1]  CLOSING SolrCore 
org.apache.solr.core.SolrCore@6d79ab9a
   [junit4]   2> 2735574 INFO  (coreCloseExecutor-10591-thread-1) [    ] 
o.a.s.m.SolrMetricManager Closing metric reporters for 
registry=solr.core.collection1, tag=1836690330
   [junit4]   2> 2735576 INFO  
(TEST-TestUseDocValuesAsStored.testMultipleSearchResults-seed#[DA2919536188098E])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testMultipleSearchResults
   [junit4]   2> 2735577 INFO  
(SUITE-TestUseDocValuesAsStored-seed#[DA2919536188098E]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ------------------------------------------------------- 
Done waiting for tracked resources to be released
   [junit4]   2> Jul 23, 2017 2:18:11 PM 
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked 
thread(s).
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): {}, 
docValues:{}, maxPointsInLeafNode=1885, maxMBSortInHeap=5.144011779818616, 
sim=RandomSimilarity(queryNorm=true): {}, locale=fi, timezone=Europe/Kiev
   [junit4]   2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 9 
(64-bit)/cpus=3,threads=1,free=152700920,total=533200896
   [junit4]   2> NOTE: All tests run in this JVM: [CdcrReplicationHandlerTest, 
UnloadDistributedZkTest, TestReplicaProperties, 
DistributedSuggestComponentTest, TestCollationFieldDocValues, 
CollectionTooManyReplicasTest, ZkCLITest, TestTrackingShardHandlerFactory, 
TestLocalFSCloudBackupRestore, TestMiniSolrCloudCluster, ShardRoutingTest, 
TestFieldCacheVsDocValues, BlobRepositoryCloudTest, ConfigSetsAPITest, 
SolrIndexSplitterTest, TestConfigSetsAPIZkFailure, TestHdfsBackupRestoreCore, 
TestPushWriter, PeerSyncTest, HdfsSyncSliceTest, 
BinaryUpdateRequestHandlerTest, DirectSolrConnectionTest, 
TestAuthorizationFramework, TestBulkSchemaConcurrent, InfoHandlerTest, 
TestLeaderElectionZkExpiry, ResourceLoaderTest, ShardSplitTest, 
OverseerCollectionConfigSetProcessorTest, ExplicitHLLTest, TestUpdate, 
QueryResultKeyTest, DocExpirationUpdateProcessorFactoryTest, 
TestClusterProperties, FastVectorHighlighterTest, BooleanFieldTest, 
TestConfigSetProperties, SuggesterWFSTTest, TestFunctionQuery, 
DistributedSpellCheckComponentTest, TestSolrConfigHandler, 
NotRequiredUniqueKeyTest, TestDeleteCollectionOnDownNodes, TestWriterPerf, 
TestReplicationHandler, DistributedFacetPivotSmallTest, TestHashPartitioner, 
TestCodecSupport, DateMathParserTest, TestSolrCoreProperties, 
BasicDistributedZkTest, TestBlendedInfixSuggestions, TestPseudoReturnFields, 
RequestHandlersTest, MultiThreadedOCPTest, CreateCollectionCleanupTest, 
TestCloudDeleteByQuery, VMParamsZkACLAndCredentialsProvidersTest, 
TestBinaryResponseWriter, HdfsChaosMonkeySafeLeaderTest, TestFieldSortValues, 
TestRestManager, TestExtendedDismaxParser, TestPHPSerializedResponseWriter, 
ReplaceNodeTest, TestDownShardTolerantSearch, TestExportWriter, 
SolrCLIZkUtilsTest, ChaosMonkeyNothingIsSafeTest, SolrSlf4jReporterTest, 
TestFieldTypeCollectionResource, OverseerRolesTest, TestGraphMLResponseWriter, 
TestHttpShardHandlerFactory, TestQuerySenderListener, MinimalSchemaTest, 
MergeStrategyTest, SyncSliceTest, TestMaxTokenLenTokenizer, 
AliasIntegrationTest, TestLegacyField, CoreAdminHandlerTest, SimpleFacetsTest, 
ScriptEngineTest, TestClusterStateMutator, TestRuleBasedAuthorizationPlugin, 
BlockJoinFacetSimpleTest, InfixSuggestersTest, TestSystemCollAutoCreate, 
TestManagedSynonymGraphFilterFactory, TestDefaultStatsCache, BufferStoreTest, 
TestOverriddenPrefixQueryForCustomFieldType, TestSolrCloudWithKerberosAlt, 
ShufflingReplicaListTransformerTest, TestStressUserVersions, RuleEngineTest, 
TestSimpleQParserPlugin, HighlighterMaxOffsetTest, 
TestCursorMarkWithoutUniqueKey, SliceStateTest, MissingSegmentRecoveryTest, 
MetricsConfigTest, TestInPlaceUpdatesStandalone, DistribJoinFromCollectionTest, 
CollectionsAPISolrJTest, ResponseLogComponentTest, 
TestRandomRequestDistribution, ReturnFieldsTest, TestNamedUpdateProcessors, 
AnalyticsMergeStrategyTest, TestPullReplicaErrorHandling, DistanceFunctionTest, 
DistributedQueryComponentCustomSortTest, SuggesterTest, 
OutOfBoxZkACLAndCredentialsProvidersTest, FieldAnalysisRequestHandlerTest, 
TestDFRSimilarityFactory, TestReqParamsAPI, SolrShardReporterTest, 
TestJsonRequest, JSONWriterTest, TestFreeTextSuggestions, 
AsyncCallRequestStatusResponseTest, TestFuzzyAnalyzedSuggestions, 
TestLegacyFieldCache, DefaultValueUpdateProcessorTest, 
IndexBasedSpellCheckerTest, LeaderInitiatedRecoveryOnShardRestartTest, 
SpatialFilterTest, TestSegmentSorting, TestShardHandlerFactory, TestNRTOpen, 
AnalysisAfterCoreReloadTest, TestRequestStatusCollectionAPI, 
CSVRequestHandlerTest, TestApiFramework, TestCloudJSONFacetJoinDomain, 
TestPerFieldSimilarityWithDefaultOverride, CoreSorterTest, 
AlternateDirectoryTest, WordBreakSolrSpellCheckerTest, OverseerTest, 
TestCloudNestedDocsSort, BigEndianAscendingWordSerializerTest, 
TestConfigOverlay, SimpleMLTQParserTest, TestReversedWildcardFilterFactory, 
TestSubQueryTransformerCrossCore, NumericFieldsTest, ForceLeaderTest, 
TestQuerySenderNoQuery, TestNumericTerms64, HdfsRecoveryZkTest, 
IndexSchemaTest, PeerSyncWithIndexFingerprintCachingTest, 
QueryElevationComponentTest, CdcrVersionReplicationTest, TestRandomDVFaceting, 
TestRTimerTree, TestManagedSchema, TestBinaryField, ConnectionReuseTest, 
DirectUpdateHandlerTest, TestSchemaNameResource, TestPrepRecovery, 
DeleteShardTest, SortSpecParsingTest, TestSizeLimitedDistributedMap, 
TestDynamicLoading, TestMacroExpander, TestClassNameShortening, 
RequestLoggingTest, TestCloudPseudoReturnFields, SortByFunctionTest, 
RecoveryZkTest, PrimitiveFieldTypeTest, MoveReplicaHDFSTest, 
MoveReplicaHDFSUlogDirTest, MoveReplicaTest, OverseerTaskQueueTest, 
ReplicationFactorTest, RestartWhileUpdatingTest, SSLMigrationTest, 
SharedFSAutoReplicaFailoverTest, SharedFSAutoReplicaFailoverUtilsTest, 
SolrCloudExampleTest, SolrXmlInZkTest, TestAuthenticationFramework, 
TestCloudInspectUtil, TestConfigSetsAPI, TestStressInPlaceUpdates, 
TestTolerantUpdateProcessorCloud, TestTolerantUpdateProcessorRandomCloud, 
TlogReplayBufferedWhileIndexingTest, TriLevelCompositeIdRoutingTest, 
TestPolicyCloud, HdfsBasicDistributedZk2Test, HdfsBasicDistributedZkTest, 
HdfsChaosMonkeyNothingIsSafeTest, HdfsNNFailoverTest, 
HdfsRestartWhileUpdatingTest, HdfsThreadLeakTest, 
HdfsTlogReplayBufferedWhileIndexingTest, HdfsWriteToMultipleCollectionsTest, 
ZkStateReaderTest, ZkStateWriterTest, RulesTest, TestConfigSets, 
TestCustomStream, TestBlobHandler, TestSQLHandlerNonCloud, 
TestSolrConfigHandlerCloud, TestSolrConfigHandlerConcurrent, 
DistributedFacetPivotLargeTest, SuggestComponentTest, TestPivotHelperCode, 
TestSlowCompositeReaderWrapper, UninvertDocValuesMergePolicyTest, 
WrapperMergePolicyFactoryTest, CheckHdfsIndexTest, TestLegacyNumericUtils, 
TestMultiValuedNumericRangeQuery, TestNumericRangeQuery64, JvmMetricsTest, 
SolrMetricManagerTest, SolrMetricReporterTest, SolrMetricsIntegrationTest, 
SolrGraphiteReporterTest, TestRawResponseWriter, TestChildDocTransformer, 
TestSubQueryTransformerDistrib, TestManagedSynonymFilterFactory, 
ManagedSchemaRoundRobinCloudTest, TestManagedSchemaThreadSafety, 
TestPointFields, TestSchemaManager, TestSchemalessBufferedUpdates, 
TestUseDocValuesAsStored]
   [junit4]   2> NOTE: reproduce with: ant test  
-Dtestcase=TestUseDocValuesAsStored -Dtests.seed=DA2919536188098E 
-Dtests.slow=true -Dtests.locale=fi -Dtests.timezone=Europe/Kiev 
-Dtests.asserts=true -Dtests.file.encoding=Cp1252
   [junit4] ERROR   0.00s J0 | TestUseDocValuesAsStored (suite) <<<
   [junit4]    > Throwable #1: java.io.IOException: Could not remove the 
following files (in the order of attempts):
   [junit4]    >    
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\init-core-data-001:
 java.nio.file.AccessDeniedException: 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001\init-core-data-001
   [junit4]    >    
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001:
 java.nio.file.DirectoryNotEmptyException: 
C:\Users\jenkins\workspace\Lucene-Solr-7.0-Windows\solr\build\solr-core\test\J0\temp\solr.schema.TestUseDocValuesAsStored_DA2919536188098E-001
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([DA2919536188098E]:0)
   [junit4]    >        at org.apache.lucene.util.IOUtils.rm(IOUtils.java:329)
   [junit4]    >        at java.base/java.lang.Thread.run(Thread.java:844)
   [junit4] Completed [638/727 (1!)] on J0 in 2.96s, 7 tests, 1 error <<< 
FAILURES!

[...truncated 36781 lines...]

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