Build: https://builds.apache.org/job/Lucene-Solr-Tests-7.x/389/

2 tests failed.
FAILED:  
junit.framework.TestSuite.org.apache.solr.client.solrj.embedded.SolrExampleStreamingBinaryTest

Error Message:
1 thread leaked from SUITE scope at 
org.apache.solr.client.solrj.embedded.SolrExampleStreamingBinaryTest:     1) 
Thread[id=2250, name=qtp1997229216-2250, state=TIMED_WAITING, 
group=TGRP-SolrExampleStreamingBinaryTest]         at 
sun.misc.Unsafe.park(Native Method)         at 
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)         
at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
         at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
         at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
         at 
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
         at 
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626) 
        at java.lang.Thread.run(Thread.java:748)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE 
scope at org.apache.solr.client.solrj.embedded.SolrExampleStreamingBinaryTest: 
   1) Thread[id=2250, name=qtp1997229216-2250, state=TIMED_WAITING, 
group=TGRP-SolrExampleStreamingBinaryTest]
        at sun.misc.Unsafe.park(Native Method)
        at 
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
        at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
        at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
        at 
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
        at 
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
        at java.lang.Thread.run(Thread.java:748)
        at __randomizedtesting.SeedInfo.seed([116E48DA5F64393B]:0)


FAILED:  
junit.framework.TestSuite.org.apache.solr.client.solrj.embedded.SolrExampleStreamingBinaryTest

Error Message:
There are still zombie threads that couldn't be terminated:    1) 
Thread[id=2250, name=qtp1997229216-2250, state=TIMED_WAITING, 
group=TGRP-SolrExampleStreamingBinaryTest]         at 
sun.misc.Unsafe.park(Native Method)         at 
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)         
at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
         at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
         at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
         at 
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
         at 
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626) 
        at java.lang.Thread.run(Thread.java:748)

Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie 
threads that couldn't be terminated:
   1) Thread[id=2250, name=qtp1997229216-2250, state=TIMED_WAITING, 
group=TGRP-SolrExampleStreamingBinaryTest]
        at sun.misc.Unsafe.park(Native Method)
        at 
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
        at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
        at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
        at 
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
        at 
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
        at java.lang.Thread.run(Thread.java:748)
        at __randomizedtesting.SeedInfo.seed([116E48DA5F64393B]:0)




Build Log:
[...truncated 15528 lines...]
   [junit4] Suite: 
org.apache.solr.client.solrj.embedded.SolrExampleStreamingBinaryTest
   [junit4]   2> 61973 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.SolrTestCaseJ4 SecureRandom sanity checks: 
test.solr.allowed.securerandom=null & java.security.egd=file:/dev/./urandom
   [junit4]   2> Creating dataDir: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/init-core-data-001
   [junit4]   2> 61974 WARN  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.SolrTestCaseJ4 startTrackingSearchers: numOpens=4 numCloses=4
   [junit4]   2> 61974 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Using TrieFields (NUMERIC_POINTS_SYSPROP=false) 
w/NUMERIC_DOCVALUES_SYSPROP=true
   [junit4]   2> 61975 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: 
@org.apache.solr.SolrTestCaseJ4$SuppressSSL(bugUrl=https://issues.apache.org/jira/browse/SOLR-5776)
   [junit4]   2> 61996 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ####initCore
   [junit4]   2> 61996 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ####initCore end
   [junit4]   2> 61997 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.SolrTestCaseJ4 Writing core.properties file to 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-002/cores/core
   [junit4]   2> 61999 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.e.j.s.Server jetty-9.4.8.v20171121, build timestamp: 
2017-11-21T22:27:37+01:00, git hash: 82b8fb23f757335bb3329d540ce37a2a2615f0a8
   [junit4]   2> 62003 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.e.j.s.session DefaultSessionIdManager workerName=node0
   [junit4]   2> 62003 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.e.j.s.session No SessionScavenger set, using defaults
   [junit4]   2> 62003 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.e.j.s.session Scavenging every 660000ms
   [junit4]   2> 62004 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.e.j.s.h.ContextHandler Started 
o.e.j.s.ServletContextHandler@73a8392d{/solr,null,AVAILABLE}
   [junit4]   2> 62005 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.e.j.s.AbstractConnector Started 
ServerConnector@4a412c26{HTTP/1.1,[http/1.1]}{127.0.0.1:48560}
   [junit4]   2> 62005 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.e.j.s.Server Started @63959ms
   [junit4]   2> 62005 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, 
hostPort=48560, 
configSetBaseDir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001,
 
coreRootDirectory=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-002/cores}
   [junit4]   2> 62006 ERROR 
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.u.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be 
missing or incomplete.
   [junit4]   2> 62006 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.s.SolrDispatchFilter  ___      _       Welcome to Apache Solr™ version 
7.3.0
   [junit4]   2> 62006 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.s.SolrDispatchFilter / __| ___| |_ _   Starting in standalone mode on 
port null
   [junit4]   2> 62006 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_|  Install dir: null
   [junit4]   2> 62006 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.s.SolrDispatchFilter |___/\___/_|_|    Start time: 
2018-02-14T14:03:27.815Z
   [junit4]   2> 62006 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.c.SolrXmlConfig Loading container configuration from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/solr.xml
   [junit4]   2> 62011 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.c.SolrXmlConfig MBean server found: 
com.sun.jmx.mbeanserver.JmxMBeanServer@195b4563, but no JMX reporters were 
configured - adding default JMX reporter.
   [junit4]   2> 62057 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.node' (registry 'solr.node') 
enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@195b4563
   [junit4]   2> 62096 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jvm' (registry 'solr.jvm') 
enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@195b4563
   [junit4]   2> 62096 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.m.r.SolrJmxReporter JMX monitoring for 'solr.jetty' (registry 
'solr.jetty') enabled at server: com.sun.jmx.mbeanserver.JmxMBeanServer@195b4563
   [junit4]   2> 62101 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.c.CorePropertiesLocator Found 1 core definitions underneath 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001
   [junit4]   2> 62101 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.c.CorePropertiesLocator Cores are: [collection1]
   [junit4]   2> 62101 INFO  (coreLoadExecutor-499-thread-1) [    ] 
o.a.s.c.TransientSolrCoreCacheDefault Allocating transient cache for 2147483647 
transient cores
   [junit4]   2> 62118 WARN  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Couldn't add files from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../contrib/extraction/lib
 filtered by .*\.jar to classpath: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../contrib/extraction/lib
   [junit4]   2> 62118 WARN  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Couldn't add files from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../dist
 filtered by solr-cell-\d.*\.jar to classpath: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../dist
   [junit4]   2> 62118 WARN  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Couldn't add files from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../contrib/clustering/lib
 filtered by .*\.jar to classpath: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../contrib/clustering/lib
   [junit4]   2> 62118 WARN  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Couldn't add files from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../dist
 filtered by solr-clustering-\d.*\.jar to classpath: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../dist
   [junit4]   2> 62119 WARN  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Couldn't add files from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../contrib/langid/lib
 filtered by .*\.jar to classpath: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../contrib/langid/lib
   [junit4]   2> 62119 WARN  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Couldn't add files from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../dist
 filtered by solr-langid-\d.*\.jar to classpath: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../dist
   [junit4]   2> 62119 WARN  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Couldn't add files from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../dist
 filtered by solr-ltr-\d.*\.jar to classpath: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../dist
   [junit4]   2> 62119 WARN  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Couldn't add files from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../contrib/velocity/lib
 filtered by .*\.jar to classpath: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../contrib/velocity/lib
   [junit4]   2> 62119 WARN  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Couldn't add files from 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../dist
 filtered by solr-velocity-\d.*\.jar to classpath: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/../../../../dist
   [junit4]   2> 62136 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.SolrIndexConfig IndexWriter infoStream solr logging is 
enabled
   [junit4]   2> 62137 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 7.3.0
   [junit4]   2> 62184 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.s.IndexSchema [collection1] Schema name=example
   [junit4]   2> 62402 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.RestManager Registered ManagedResource impl 
org.apache.solr.rest.schema.analysis.ManagedWordSetResource for path 
/schema/analysis/stopwords/english
   [junit4]   2> 62402 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.RestManager Registered ManagedResource impl 
org.apache.solr.rest.schema.analysis.ManagedSynonymGraphFilterFactory$SynonymManager
 for path /schema/analysis/synonyms/english
   [junit4]   2> 62402 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.RestManager Added observer of type 
org.apache.solr.rest.schema.analysis.ManagedStopFilterFactory to existing 
ManagedResource /schema/analysis/stopwords/english
   [junit4]   2> 62402 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.RestManager Added observer of type 
org.apache.solr.rest.schema.analysis.ManagedSynonymGraphFilterFactory to 
existing ManagedResource /schema/analysis/synonyms/english
   [junit4]   2> 62403 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.s.IndexSchema Loaded schema example/1.6 with uniqueid 
field id
   [junit4]   2> 62403 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.RestManager Added observer of type 
org.apache.solr.rest.schema.analysis.ManagedStopFilterFactory to existing 
ManagedResource /schema/analysis/stopwords/english
   [junit4]   2> 62403 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.RestManager Added observer of type 
org.apache.solr.rest.schema.analysis.ManagedSynonymGraphFilterFactory to 
existing ManagedResource /schema/analysis/synonyms/english
   [junit4]   2> 62403 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.RestManager Added observer of type 
org.apache.solr.rest.schema.analysis.ManagedStopFilterFactory to existing 
ManagedResource /schema/analysis/stopwords/english
   [junit4]   2> 62403 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.RestManager Added observer of type 
org.apache.solr.rest.schema.analysis.ManagedSynonymGraphFilterFactory to 
existing ManagedResource /schema/analysis/synonyms/english
   [junit4]   2> 62468 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.CoreContainer Creating SolrCore 'collection1' using 
configuration from instancedir 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1,
 trusted=true
   [junit4]   2> 62468 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.m.r.SolrJmxReporter JMX monitoring for 
'solr.core.collection1' (registry 'solr.core.collection1') enabled at server: 
com.sun.jmx.mbeanserver.JmxMBeanServer@195b4563
   [junit4]   2> 62468 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.SolrCore solr.RecoveryStrategy.Builder
   [junit4]   2> 62468 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.c.SolrCore [[collection1] ] Opening new SolrCore at 
[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1],
 
dataDir=[/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/data/]
   [junit4]   2> 62470 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-499-thread-1]: 
init: current segments file is "segments"; 
deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@16f23a21
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-499-thread-1]: 
now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-499-thread-1]: 
0 msec to checkpoint
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
init: create=true
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
   [junit4]   2> dir=MockDirectoryWrapper(RAMDirectory@2fcaf343 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1bcc63cf)
   [junit4]   2> index=
   [junit4]   2> version=7.3.0
   [junit4]   2> 
analyzer=org.apache.solr.update.SolrIndexConfig$DelayedSchemaAnalyzer
   [junit4]   2> ramBufferSizeMB=100.0
   [junit4]   2> maxBufferedDocs=-1
   [junit4]   2> mergedSegmentWarmer=null
   [junit4]   2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
   [junit4]   2> commit=null
   [junit4]   2> openMode=CREATE
   [junit4]   2> 
similarity=org.apache.solr.search.similarities.SchemaSimilarityFactory$SchemaSimilarity
   [junit4]   2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, 
maxMergeCount=-1, ioThrottle=true
   [junit4]   2> codec=Lucene70
   [junit4]   2> infoStream=org.apache.solr.update.LoggingInfoStream
   [junit4]   2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, 
maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, 
forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, 
maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
   [junit4]   2> 
indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@cfb8249
   [junit4]   2> readerPooling=true
   [junit4]   2> perThreadHardLimitMB=1945
   [junit4]   2> useCompoundFile=false
   [junit4]   2> commitOnClose=true
   [junit4]   2> indexSort=null
   [junit4]   2> checkPendingFlushOnUpdate=true
   [junit4]   2> writer=org.apache.solr.update.SolrIndexWriter@7453287e
   [junit4]   2> 
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
MMapDirectory.UNMAP_SUPPORTED=true
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
now flush at close
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]:   
start flush: applyAllDeletes=true
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]:   
index before flush 
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-499-thread-1]: 
startFullFlush
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-499-thread-1]: 
coreLoadExecutor-499-thread-1 finishFullFlush success=true
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
now apply all deletes for all segments buffered updates bytesUsed=0 reader pool 
bytesUsed=0
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [BD][coreLoadExecutor-499-thread-1]: 
waitApply: no deletes to apply
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [MS][coreLoadExecutor-499-thread-1]: 
initDynamicDefaults spins=true maxThreadCount=1 maxMergeCount=6
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [MS][coreLoadExecutor-499-thread-1]: 
updateMergeThreads ioThrottle=true targetMBPerSec=10240.0 MB/sec
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [MS][coreLoadExecutor-499-thread-1]: 
now merge
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [MS][coreLoadExecutor-499-thread-1]:   
index: 
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [MS][coreLoadExecutor-499-thread-1]:   
no more merges pending; now return
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
waitForMerges
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
waitForMerges done
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
commit: start
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
commit: enter lock
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
commit: now prepare
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
prepareCommit: flush
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]:   
index before flush 
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-499-thread-1]: 
startFullFlush
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
now apply all deletes for all segments buffered updates bytesUsed=0 reader pool 
bytesUsed=0
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [BD][coreLoadExecutor-499-thread-1]: 
waitApply: no deletes to apply
   [junit4]   2> 62471 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-499-thread-1]: 
coreLoadExecutor-499-thread-1 finishFullFlush success=true
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
startCommit(): start
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
startCommit index= changeCount=2
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
startCommit: wrote pending segments file "pending_segments_1"
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
done all syncs: []
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
commit: pendingCommit != null
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
commit: done writing segments file "segments_1"
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-499-thread-1]: 
now checkpoint "" [0 segments ; isCommit = true]
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-499-thread-1]: 
0 msec to checkpoint
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
commit: took 0.6 msec
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
commit: done
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
rollback
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
all running merges have aborted
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
rollback: done finish merges
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-499-thread-1]: 
abort
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-499-thread-1]: 
done abort success=true
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
rollback: infos=
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-499-thread-1]: 
now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 62472 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-499-thread-1]: 
0 msec to checkpoint
   [junit4]   2> 62473 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.XSLTResponseWriter xsltCacheLifetimeSeconds=5
   [junit4]   2> 62546 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.UpdateHandler Using UpdateLog implementation: 
org.apache.solr.update.UpdateLog
   [junit4]   2> 62546 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= 
defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 
numVersionBuckets=65536
   [junit4]   2> 62547 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.CommitTracker Hard AutoCommit: if uncommited for 
15000ms; 
   [junit4]   2> 62547 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
   [junit4]   2> 62552 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-499-thread-1]: 
init: current segments file is "segments_1"; 
deletionPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper@16f23a21
   [junit4]   2> 62552 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-499-thread-1]: 
init: load commit "segments_1"
   [junit4]   2> 62552 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-499-thread-1]: 
now checkpoint "" [0 segments ; isCommit = false]
   [junit4]   2> 62552 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreLoadExecutor-499-thread-1]: 
0 msec to checkpoint
   [junit4]   2> 62552 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
init: create=false
   [junit4]   2> 62552 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
   [junit4]   2> dir=MockDirectoryWrapper(RAMDirectory@2fcaf343 
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@1bcc63cf)
   [junit4]   2> index=
   [junit4]   2> version=7.3.0
   [junit4]   2> 
analyzer=org.apache.solr.update.SolrIndexConfig$DelayedSchemaAnalyzer
   [junit4]   2> ramBufferSizeMB=100.0
   [junit4]   2> maxBufferedDocs=-1
   [junit4]   2> mergedSegmentWarmer=null
   [junit4]   2> delPolicy=org.apache.solr.core.IndexDeletionPolicyWrapper
   [junit4]   2> commit=null
   [junit4]   2> openMode=APPEND
   [junit4]   2> 
similarity=org.apache.solr.search.similarities.SchemaSimilarityFactory$SchemaSimilarity
   [junit4]   2> mergeScheduler=ConcurrentMergeScheduler: maxThreadCount=-1, 
maxMergeCount=-1, ioThrottle=true
   [junit4]   2> codec=Lucene70
   [junit4]   2> infoStream=org.apache.solr.update.LoggingInfoStream
   [junit4]   2> mergePolicy=[TieredMergePolicy: maxMergeAtOnce=10, 
maxMergeAtOnceExplicit=30, maxMergedSegmentMB=5120.0, floorSegmentMB=2.0, 
forceMergeDeletesPctAllowed=10.0, segmentsPerTier=10.0, 
maxCFSSegmentSizeMB=8.796093022207999E12, noCFSRatio=0.1
   [junit4]   2> 
indexerThreadPool=org.apache.lucene.index.DocumentsWriterPerThreadPool@3bb02507
   [junit4]   2> readerPooling=true
   [junit4]   2> perThreadHardLimitMB=1945
   [junit4]   2> useCompoundFile=false
   [junit4]   2> commitOnClose=true
   [junit4]   2> indexSort=null
   [junit4]   2> checkPendingFlushOnUpdate=true
   [junit4]   2> writer=org.apache.solr.update.SolrIndexWriter@70335e99
   [junit4]   2> 
   [junit4]   2> 62552 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
MMapDirectory.UNMAP_SUPPORTED=true
   [junit4]   2> 62552 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
flush at getReader
   [junit4]   2> 62552 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-499-thread-1]: 
startFullFlush
   [junit4]   2> 62552 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
now apply all deletes for all segments buffered updates bytesUsed=0 reader pool 
bytesUsed=0
   [junit4]   2> 62552 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [BD][coreLoadExecutor-499-thread-1]: 
waitApply: no deletes to apply
   [junit4]   2> 62553 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
incRefDeleter for NRT reader version=2 segments=
   [junit4]   2> 62553 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
return reader version=2 reader=StandardDirectoryReader(segments_1:2:nrt)
   [junit4]   2> 62553 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [DW][coreLoadExecutor-499-thread-1]: 
coreLoadExecutor-499-thread-1 finishFullFlush success=true
   [junit4]   2> 62553 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreLoadExecutor-499-thread-1]: 
getReader took 1 msec
   [junit4]   2> 62553 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.s.SolrIndexSearcher Opening 
[Searcher@26aaa8bf[collection1] main]
   [junit4]   2> 62554 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.ManagedResourceStorage File-based storage initialized to 
use dir: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/conf
   [junit4]   2> 62554 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.ManagedResourceStorage Loaded LinkedHashMap at path 
_rest_managed.json using 
file:dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/conf
   [junit4]   2> 62554 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.ManagedResource Loaded initArgs {} for /rest/managed
   [junit4]   2> 62554 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.ManagedResourceStorage Loaded LinkedHashMap at path 
_schema_analysis_stopwords_english.json using 
file:dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/conf
   [junit4]   2> 62554 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.ManagedResource Loaded initArgs {ignoreCase=true} for 
/schema/analysis/stopwords/english
   [junit4]   2> 62554 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.s.a.ManagedWordSetResource Loaded 35 words for 
/schema/analysis/stopwords/english
   [junit4]   2> 62554 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.ManagedResource Notified 4 observers of 
/schema/analysis/stopwords/english
   [junit4]   2> 62554 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.ManagedResourceStorage Loaded LinkedHashMap at path 
_schema_analysis_synonyms_english.json using 
file:dir=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/conf
   [junit4]   2> 62554 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.ManagedResource Loaded initArgs 
{ignoreCase=true,format=solr} for /schema/analysis/synonyms/english
   [junit4]   2> 62554 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.s.a.ManagedSynonymGraphFilterFactory Loaded 3 synonym 
mappings for /schema/analysis/synonyms/english
   [junit4]   2> 62556 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.r.ManagedResource Notified 4 observers of 
/schema/analysis/synonyms/english
   [junit4]   2> 62558 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.h.c.SpellCheckComponent Initializing spell checkers
   [junit4]   2> 62558 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.s.DirectSolrSpellChecker init: 
{name=default,field=text,classname=solr.DirectSolrSpellChecker,distanceMeasure=internal,accuracy=0.5,maxEdits=2,minPrefix=1,maxInspections=5,minQueryLength=4,maxQueryFrequency=0.01}
   [junit4]   2> 62558 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.h.c.SuggestComponent Initializing SuggestComponent
   [junit4]   2> 62558 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.s.s.SolrSuggester init: 
{name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string,buildOnStartup=false}
   [junit4]   2> 62559 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.s.s.SolrSuggester Dictionary loaded with params: 
{name=mySuggester,lookupImpl=FuzzyLookupFactory,dictionaryImpl=DocumentDictionaryFactory,field=cat,weightField=price,suggestAnalyzerFieldType=string,buildOnStartup=false}
   [junit4]   2> 62559 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.h.c.QueryElevationComponent Loading QueryElevation from: 
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-7.x/solr/build/solr-solrj/test/J0/temp/solr.client.solrj.embedded.SolrExampleStreamingBinaryTest_116E48DA5F64393B-001/tempDir-001/collection1/conf/elevate.xml
   [junit4]   2> 62570 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000ms.
   [junit4]   2> 62570 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.QuerySenderListener QuerySenderListener sending requests to 
Searcher@26aaa8bf[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 62571 INFO  (coreLoadExecutor-499-thread-1) [    
x:collection1] o.a.s.u.UpdateLog Could not find max version in index or recent 
updates, using new clock 1592385348179066880
   [junit4]   2> 62571 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=null path=null 
params={q=static+firstSearcher+warming+in+solrconfig.xml&distrib=false&event=firstSearcher}
 hits=0 status=0 QTime=0
   [junit4]   2> 62571 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.QuerySenderListener QuerySenderListener done.
   [junit4]   2> 62571 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: default
   [junit4]   2> 62571 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.h.c.SpellCheckComponent Loading spell index for spellchecker: wordbreak
   [junit4]   2> 62573 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.SolrJettyTestBase Jetty Assigned Port#48560
   [junit4]   2> 62573 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@26aaa8bf[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 62576 INFO  
(TEST-SolrExampleStreamingBinaryTest.testRawFields-seed#[116E48DA5F64393B]) [   
 ] o.a.s.SolrTestCaseJ4 ###Starting testRawFields
   [junit4]   2> 62585 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2205]: anyChanges? numDocsInRam=0 
deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 62585 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2205]: anyChanges? numDocsInRam=0 
deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 62585 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2205]: nrtIsCurrent: infoVersion 
matches: true; DW changes: true; BD changes: false
   [junit4]   2> 62585 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2205]: flush at getReader
   [junit4]   2> 62585 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2205]: startFullFlush
   [junit4]   2> 62585 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2205]: anyChanges? numDocsInRam=0 
deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 62586 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2205]: qtp1997229216-2205: flush 
naked frozen global deletes
   [junit4]   2> 62586 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2205]: compressed 76 to 48 bytes 
(63.16%) for deletes/updates; private segment null
   [junit4]   2> 62588 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2205]: push new packet (delGen=1 
numDeleteQuerys=1 bytesUsed=48), packetCount=1, bytesUsed=0.000 MB
   [junit4]   2> 62588 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2205]: flush: push buffered 
updates: delGen=1 numDeleteQuerys=1 bytesUsed=48
   [junit4]   2> 62589 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2205]: packet matches no segments
   [junit4]   2> 62589 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2205]: finished packet delGen=1 
now completedDelGen=1
   [junit4]   2> 62589 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2205]: done apply del packet 
(delGen=1 numDeleteQuerys=1 bytesUsed=48) to 0 segments; 0 new deletes/updates; 
took 0.000 sec; 0 packets remain
   [junit4]   2> 62589 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2205]: now apply all deletes for 
all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
   [junit4]   2> 62589 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2205]: waitApply: no deletes to 
apply
   [junit4]   2> 62589 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2205]: incRefDeleter for NRT 
reader version=2 segments=
   [junit4]   2> 62589 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2205]: return reader version=2 
reader=StandardDirectoryReader(segments_1:2:nrt)
   [junit4]   2> 62589 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2205]: qtp1997229216-2205 
finishFullFlush success=true
   [junit4]   2> 62589 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2205]: getReader took 4 msec
   [junit4]   2> 62589 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2205]: decRefDeleter for NRT 
reader version=2 segments=
   [junit4]   2> 62604 INFO  (qtp1997229216-2205) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/solr path=/update 
params={wt=javabin&version=2}{deleteByQuery=*:* (-1592385348189552640)} 0 23
   [junit4]   2> 62625 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/solr path=/update 
params={wt=javabin&version=2}{add=[111 (1592385348224155648)]} 0 11
   [junit4]   2> 62626 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1592385348236738560,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 62626 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@70335e99 
commitCommandVersion:1592385348236738560
   [junit4]   2> 62626 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: commit: start
   [junit4]   2> 62626 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: commit: enter lock
   [junit4]   2> 62626 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: commit: now prepare
   [junit4]   2> 62626 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: prepareCommit: flush
   [junit4]   2> 62626 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]:   index before flush 
   [junit4]   2> 62626 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2209]: startFullFlush
   [junit4]   2> 62626 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2209]: anyChanges? numDocsInRam=1 
deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 62626 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWFC][qtp1997229216-2209]: addFlushableState 
DocumentsWriterPerThread [pendingDeletes=gen=0, segment=_0, aborted=false, 
numDocsInRAM=1, deleteQueue=DWDQ: [ generation: 2 ]]
   [junit4]   2> 62627 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2209]: compressed 167 to 1040 
bytes (622.75%) for deletes/updates; private segment null
   [junit4]   2> 62627 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2209]: flush postings as segment 
_0 numDocs=1
   [junit4]   2> 62628 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: 1 msec to write norms
   [junit4]   2> 62629 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: 0 msec to write docValues
   [junit4]   2> 62629 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: 0 msec to write points
   [junit4]   2> 62629 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: 0 msec to finish stored 
fields
   [junit4]   2> 62630 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: 1 msec to write postings 
and finish vectors
   [junit4]   2> 62630 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: 0 msec to write fieldInfos
   [junit4]   2> 62630 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2209]: new segment has 0 deleted 
docs
   [junit4]   2> 62630 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2209]: new segment has no 
vectors; norms; docValues; prox; freqs
   [junit4]   2> 62630 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2209]: 
flushedFiles=[_0_Lucene50_0.doc, _0_Lucene50_0.tim, _0_Lucene70_0.dvd, 
_0_Lucene50_0.pos, _0.nvd, _0.fdx, _0_Lucene50_0.tip, _0.fdt, _0.nvm, 
_0_Lucene70_0.dvm, _0.fnm]
   [junit4]   2> 62630 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2209]: flushed codec=Lucene70
   [junit4]   2> 62631 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2209]: flushed: segment=_0 
ramUsed=0.112 MB newFlushedSize=0.002 MB docs/MB=496.955
   [junit4]   2> 62631 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2209]: flush time 3.931096 msec
   [junit4]   2> 62631 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2209]: publishFlushedSegment 
seg-private updates=null
   [junit4]   2> 62631 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: publishFlushedSegment 
_0(7.3.0):C1
   [junit4]   2> 62631 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2209]: push new packet (delGen=2 
numDeleteTerms=1 bytesUsed=1040), packetCount=1, bytesUsed=0.001 MB
   [junit4]   2> 62631 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2209]: finished packet delGen=3 
now completedDelGen=1
   [junit4]   2> 62631 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: publish sets newSegment 
delGen=3 seg=_0(7.3.0):C1
   [junit4]   2> 62631 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2209]: now checkpoint 
"_0(7.3.0):C1" [1 segments ; isCommit = false]
   [junit4]   2> 62631 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2209]: 0 msec to checkpoint
   [junit4]   2> 62631 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2209]: packet matches no segments
   [junit4]   2> 62631 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2209]: finished packet delGen=2 
now completedDelGen=3
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2209]: done apply del packet 
(delGen=2 numDeleteTerms=1 bytesUsed=1040) to 0 segments; 0 new 
deletes/updates; took 0.000 sec; 0 packets remain
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: now apply all deletes for 
all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2209]: waitApply: no deletes to 
apply
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2209]: qtp1997229216-2209 
finishFullFlush success=true
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: startCommit(): start
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: startCommit 
index=_0(7.3.0):C1 changeCount=4
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: startCommit: wrote pending 
segments file "pending_segments_2"
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: done all syncs: [_0.si, 
_0_Lucene50_0.doc, _0_Lucene50_0.tim, _0_Lucene70_0.dvd, _0_Lucene50_0.pos, 
_0.nvd, _0.fdx, _0_Lucene50_0.tip, _0.fdt, _0_Lucene70_0.dvm, _0.nvm, _0.fnm]
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: commit: pendingCommit != 
null
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: commit: done writing 
segments file "segments_2"
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2209]: now checkpoint 
"_0(7.3.0):C1" [1 segments ; isCommit = true]
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2209]: deleteCommits: now decRef 
commit "segments_1"
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2209]: delete [segments_1]
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2209]: 0 msec to checkpoint
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: commit: took 6.1 msec
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: commit: done
   [junit4]   2> 62632 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [TMP][qtp1997229216-2209]: findMerges: 1 segments
   [junit4]   2> 62633 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [TMP][qtp1997229216-2209]:   seg=_0(7.3.0):C1 
size=0.002 MB [floored]
   [junit4]   2> 62633 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [TMP][qtp1997229216-2209]:   allowedSegmentCount=1 vs 
count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 62633 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [MS][qtp1997229216-2209]: initDynamicDefaults 
spins=true maxThreadCount=1 maxMergeCount=6
   [junit4]   2> 62633 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [MS][qtp1997229216-2209]: now merge
   [junit4]   2> 62633 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [MS][qtp1997229216-2209]:   index: _0(7.3.0):C1
   [junit4]   2> 62633 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [MS][qtp1997229216-2209]:   no more merges pending; 
now return
   [junit4]   2> 62633 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: nrtIsCurrent: infoVersion 
matches: false; DW changes: false; BD changes: false
   [junit4]   2> 62633 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: flush at getReader
   [junit4]   2> 62633 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2209]: startFullFlush
   [junit4]   2> 62633 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: now apply all deletes for 
all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
   [junit4]   2> 62633 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2209]: waitApply: no deletes to 
apply
   [junit4]   2> 62677 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: incRefDeleter for NRT 
reader version=6 segments=_0(7.3.0):C1
   [junit4]   2> 62677 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: return reader version=6 
reader=StandardDirectoryReader(segments_2:6:nrt _0(7.3.0):C1)
   [junit4]   2> 62677 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2209]: qtp1997229216-2209 
finishFullFlush success=true
   [junit4]   2> 62677 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2209]: getReader took 44 msec
   [junit4]   2> 62677 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@67499fc[collection1] main]
   [junit4]   2> 62678 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.QuerySenderListener QuerySenderListener sending requests to 
Searcher@67499fc[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.3.0):C1)))}
   [junit4]   2> 62678 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.QuerySenderListener QuerySenderListener done.
   [junit4]   2> 62680 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@67499fc[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.3.0):C1)))}
   [junit4]   2> 62680 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.u.LoggingInfoStream 
[IW][searcherExecutor-500-thread-1-processing-x:collection1]: decRefDeleter for 
NRT reader version=2 segments=
   [junit4]   2> 62680 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 62680 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/solr path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 54
   [junit4]   2> 62690 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/solr path=/select 
params={q=*:*&fl=id,json_s:[json],xml_s:[xml]&wt=javabin&version=2} hits=1 
status=0 QTime=8
   [junit4]   2> 62691 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/solr path=/select 
params={q=*:*&fl=id,json_s:[json],xml_s:[xml]&wt=json&version=2.2} hits=1 
status=0 QTime=0
   [junit4]   2> 62696 INFO  (qtp1997229216-2209) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/solr path=/select 
params={q=*:*&fl=id,json_s:[json],xml_s:[xml]&wt=xml&version=2.2} hits=1 
status=0 QTime=0
   [junit4]   2> 62700 INFO  
(TEST-SolrExampleStreamingBinaryTest.testRawFields-seed#[116E48DA5F64393B]) [   
 ] o.a.s.SolrTestCaseJ4 ###Ending testRawFields
   [junit4]   2> 62705 INFO  
(TEST-SolrExampleStreamingBinaryTest.testPivotFacetsQueries-seed#[116E48DA5F64393B])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testPivotFacetsQueries
   [junit4]   2> 62714 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2207]: anyChanges? numDocsInRam=0 
deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 62714 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2207]: anyChanges? numDocsInRam=0 
deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 62714 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2207]: nrtIsCurrent: infoVersion 
matches: true; DW changes: true; BD changes: false
   [junit4]   2> 62714 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2207]: flush at getReader
   [junit4]   2> 62714 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2207]: startFullFlush
   [junit4]   2> 62714 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2207]: anyChanges? numDocsInRam=0 
deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 62714 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2207]: qtp1997229216-2207: flush 
naked frozen global deletes
   [junit4]   2> 62714 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2207]: compressed 76 to 48 bytes 
(63.16%) for deletes/updates; private segment null
   [junit4]   2> 62714 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2207]: push new packet (delGen=4 
numDeleteQuerys=1 bytesUsed=48), packetCount=1, bytesUsed=0.000 MB
   [junit4]   2> 62714 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2207]: flush: push buffered 
updates: delGen=4 numDeleteQuerys=1 bytesUsed=48
   [junit4]   2> 62714 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2207]: now apply del packet 
(delGen=4 numDeleteQuerys=1 bytesUsed=48) to 1 segments, mergeGen 0
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2207]: applyQueryDeletes took 0.32 
msec for 1 segments and 1 queries; 1 new deletions
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2207]: closeSegmentStates: 1 new 
deleted documents; pool 1 packets; bytesUsed=0
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2207]: now checkpoint 
"_0(7.3.0):C1/1" [1 segments ; isCommit = false]
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2207]: 0 msec to checkpoint
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2207]: drop 100% deleted segments: 
_0(7.3.0):C1/1
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2207]: now checkpoint "" [0 
segments ; isCommit = false]
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2207]: 0 msec to checkpoint
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2207]: done inner apply del packet 
(delGen=4 numDeleteQuerys=1 bytesUsed=48) to 1 segments; 1 new deletes/updates; 
took 0.001 sec
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2207]: finished packet delGen=4 
now completedDelGen=4
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2207]: done apply del packet 
(delGen=4 numDeleteQuerys=1 bytesUsed=48) to 1 segments; 1 new deletes/updates; 
took 0.001 sec; 0 packets remain
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2207]: now apply all deletes for 
all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2207]: waitApply: no deletes to 
apply
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2207]: incRefDeleter for NRT 
reader version=8 segments=
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2207]: return reader version=8 
reader=StandardDirectoryReader(segments_2:8:nrt)
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2207]: qtp1997229216-2207 
finishFullFlush success=true
   [junit4]   2> 62715 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [TMP][qtp1997229216-2207]: findMerges: 0 segments
   [junit4]   2> 62718 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [MS][qtp1997229216-2207]: now merge
   [junit4]   2> 62718 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [MS][qtp1997229216-2207]:   index: 
   [junit4]   2> 62718 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [MS][qtp1997229216-2207]:   no more merges pending; 
now return
   [junit4]   2> 62718 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2207]: getReader took 4 msec
   [junit4]   2> 62718 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@1b631908[collection1] realtime]
   [junit4]   2> 62718 INFO  (qtp1997229216-2207) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/solr path=/update 
params={wt=javabin&version=2}{deleteByQuery=*:* (-1592385348327964672)} 0 5
   [junit4]   2> 62719 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1592385348334256128,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 62720 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@70335e99 
commitCommandVersion:1592385348334256128
   [junit4]   2> 62720 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: start
   [junit4]   2> 62720 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: enter lock
   [junit4]   2> 62720 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: now prepare
   [junit4]   2> 62720 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: prepareCommit: flush
   [junit4]   2> 62720 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]:   index before flush 
   [junit4]   2> 62720 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: startFullFlush
   [junit4]   2> 62720 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: now apply all deletes for 
all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
   [junit4]   2> 62720 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: waitApply: no deletes to 
apply
   [junit4]   2> 62720 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: qtp1997229216-2210 
finishFullFlush success=true
   [junit4]   2> 62720 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: startCommit(): start
   [junit4]   2> 62720 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: startCommit index= 
changeCount=8
   [junit4]   2> 62724 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: startCommit: wrote pending 
segments file "pending_segments_3"
   [junit4]   2> 62724 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: done all syncs: []
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: pendingCommit != 
null
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: done writing 
segments file "segments_3"
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: now checkpoint "" [0 
segments ; isCommit = true]
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: deleteCommits: now decRef 
commit "segments_2"
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: delete [segments_2]
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: 0 msec to checkpoint
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: took 4.9 msec
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: done
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: nrtIsCurrent: infoVersion 
matches: false; DW changes: false; BD changes: false
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: flush at getReader
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: startFullFlush
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: now apply all deletes for 
all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: waitApply: no deletes to 
apply
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: incRefDeleter for NRT 
reader version=10 segments=
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: return reader version=10 
reader=StandardDirectoryReader(segments_3:10:nrt)
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: qtp1997229216-2210 
finishFullFlush success=true
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: getReader took 0 msec
   [junit4]   2> 62725 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@2bd3d180[collection1] main]
   [junit4]   2> 62726 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: decRefDeleter for NRT 
reader version=8 segments=
   [junit4]   2> 62726 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 62726 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.QuerySenderListener QuerySenderListener sending requests to 
Searcher@2bd3d180[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 62726 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.QuerySenderListener QuerySenderListener done.
   [junit4]   2> 62728 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@2bd3d180[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader())}
   [junit4]   2> 62728 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.u.LoggingInfoStream 
[IFD][searcherExecutor-500-thread-1-processing-x:collection1]: delete [_0.si, 
_0_Lucene50_0.doc, _0_Lucene50_0.tim, _0_Lucene70_0.dvd, _0_Lucene50_0.pos, 
_0.nvd, _0.fdx, _0_Lucene50_0.tip, _0.fdt, _0_Lucene70_0.dvm, _0.nvm, _0.fnm]
   [junit4]   2> 62728 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.u.LoggingInfoStream 
[IW][searcherExecutor-500-thread-1-processing-x:collection1]: decRefDeleter for 
NRT reader version=6 segments=_0(7.3.0):C1
   [junit4]   2> 62729 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/solr path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 9
   [junit4]   2> 62730 INFO  (qtp1997229216-2211) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/solr path=/select 
params={q=*:*&wt=javabin&version=2} hits=0 status=0 QTime=0
   [junit4]   2> 62762 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/solr path=/update 
params={wt=javabin&version=2}{add=[1 (1592385348372004864), 2 
(1592385348376199168), 3 (1592385348377247744), 4 (1592385348377247745), 5 
(1592385348377247746), 6 (1592385348377247747), 7 (1592385348378296320), 8 
(1592385348378296321), 9 (1592385348378296322), 10 (1592385348378296323), ... 
(12 adds)]} 0 7
   [junit4]   2> 62765 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 start 
commit{_version_=1592385348382490624,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
   [junit4]   2> 62766 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.SolrIndexWriter Calling setCommitData with 
IW:org.apache.solr.update.SolrIndexWriter@70335e99 
commitCommandVersion:1592385348382490624
   [junit4]   2> 62766 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: start
   [junit4]   2> 62766 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: enter lock
   [junit4]   2> 62766 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: now prepare
   [junit4]   2> 62766 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: prepareCommit: flush
   [junit4]   2> 62766 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]:   index before flush 
   [junit4]   2> 62766 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: startFullFlush
   [junit4]   2> 62766 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: anyChanges? numDocsInRam=12 
deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 62766 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWFC][qtp1997229216-2210]: addFlushableState 
DocumentsWriterPerThread [pendingDeletes=gen=0 11 deleted terms (unique 
count=11) bytesUsed=1818, segment=_1, aborted=false, numDocsInRAM=12, 
deleteQueue=DWDQ: [ generation: 7 ]]
   [junit4]   2> 62766 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: compressed 1983 to 1040 
bytes (52.45%) for deletes/updates; private segment null
   [junit4]   2> 62766 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2210]: flush postings as segment 
_1 numDocs=12
   [junit4]   2> 62766 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: 0 msec to write norms
   [junit4]   2> 62773 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: 6 msec to write docValues
   [junit4]   2> 62778 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: 5 msec to write points
   [junit4]   2> 62778 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: 0 msec to finish stored 
fields
   [junit4]   2> 62779 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: 0 msec to write postings 
and finish vectors
   [junit4]   2> 62779 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: 0 msec to write fieldInfos
   [junit4]   2> 62779 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2210]: new segment has 0 deleted 
docs
   [junit4]   2> 62779 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2210]: new segment has no 
vectors; norms; docValues; prox; freqs
   [junit4]   2> 62779 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2210]: 
flushedFiles=[_1_Lucene70_0.dvd, _1.nvd, _1.dim, _1.nvm, _1.fnm, _1.dii, 
_1_Lucene50_0.doc, _1_Lucene50_0.tim, _1_Lucene50_0.pos, _1.fdx, _1.fdt, 
_1_Lucene70_0.dvm, _1_Lucene50_0.tip]
   [junit4]   2> 62779 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2210]: flushed codec=Lucene70
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2210]: flushed: segment=_1 
ramUsed=0.232 MB newFlushedSize=0.003 MB docs/MB=3,518.711
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DWPT][qtp1997229216-2210]: flush time 13.700726 msec
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: publishFlushedSegment 
seg-private updates=null
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: publishFlushedSegment 
_1(7.3.0):C12
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: push new packet (delGen=5 
numDeleteTerms=12 bytesUsed=1040), packetCount=1, bytesUsed=0.001 MB
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: finished packet delGen=6 
now completedDelGen=4
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: publish sets newSegment 
delGen=6 seg=_1(7.3.0):C12
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: now checkpoint 
"_1(7.3.0):C12" [1 segments ; isCommit = false]
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: 0 msec to checkpoint
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: packet matches no segments
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: finished packet delGen=5 
now completedDelGen=6
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: done apply del packet 
(delGen=5 numDeleteTerms=12 bytesUsed=1040) to 0 segments; 0 new 
deletes/updates; took 0.000 sec; 0 packets remain
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: now apply all deletes for 
all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: waitApply: no deletes to 
apply
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: qtp1997229216-2210 
finishFullFlush success=true
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: startCommit(): start
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: startCommit 
index=_1(7.3.0):C12 changeCount=12
   [junit4]   2> 62780 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: startCommit: wrote pending 
segments file "pending_segments_4"
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: done all syncs: [_1.si, 
_1_Lucene70_0.dvd, _1.nvd, _1.dim, _1.nvm, _1.fnm, _1.dii, _1_Lucene50_0.doc, 
_1_Lucene50_0.tim, _1_Lucene50_0.pos, _1.fdx, _1.fdt, _1_Lucene70_0.dvm, 
_1_Lucene50_0.tip]
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: pendingCommit != 
null
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: done writing 
segments file "segments_4"
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: now checkpoint 
"_1(7.3.0):C12" [1 segments ; isCommit = true]
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: deleteCommits: now decRef 
commit "segments_3"
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: delete [segments_3]
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: 0 msec to checkpoint
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: took 15.2 msec
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: commit: done
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [TMP][qtp1997229216-2210]: findMerges: 1 segments
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [TMP][qtp1997229216-2210]:   seg=_1(7.3.0):C12 
size=0.004 MB [floored]
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [TMP][qtp1997229216-2210]:   allowedSegmentCount=1 vs 
count=1 (eligible count=1) tooBigCount=0
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [MS][qtp1997229216-2210]: now merge
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [MS][qtp1997229216-2210]:   index: _1(7.3.0):C12
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [MS][qtp1997229216-2210]:   no more merges pending; 
now return
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: nrtIsCurrent: infoVersion 
matches: false; DW changes: false; BD changes: false
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: flush at getReader
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: startFullFlush
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: now apply all deletes for 
all segments buffered updates bytesUsed=0 reader pool bytesUsed=0
   [junit4]   2> 62781 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: waitApply: no deletes to 
apply
   [junit4]   2> 62783 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: incRefDeleter for NRT 
reader version=14 segments=_1(7.3.0):C12
   [junit4]   2> 62783 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: return reader version=14 
reader=StandardDirectoryReader(segments_4:14:nrt _1(7.3.0):C12)
   [junit4]   2> 62784 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: qtp1997229216-2210 
finishFullFlush success=true
   [junit4]   2> 62784 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: getReader took 3 msec
   [junit4]   2> 62784 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.s.SolrIndexSearcher Opening [Searcher@7b8c8b8b[collection1] main]
   [junit4]   2> 62784 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.QuerySenderListener QuerySenderListener sending requests to 
Searcher@7b8c8b8b[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.3.0):C12)))}
   [junit4]   2> 62784 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.QuerySenderListener QuerySenderListener done.
   [junit4]   2> 62787 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.c.SolrCore [collection1] Registered new searcher 
Searcher@7b8c8b8b[collection1] 
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_1(7.3.0):C12)))}
   [junit4]   2> 62787 INFO  
(searcherExecutor-500-thread-1-processing-x:collection1) [    x:collection1] 
o.a.s.u.LoggingInfoStream 
[IW][searcherExecutor-500-thread-1-processing-x:collection1]: decRefDeleter for 
NRT reader version=10 segments=
   [junit4]   2> 62787 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.DirectUpdateHandler2 end_commit_flush
   [junit4]   2> 62787 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.p.LogUpdateProcessorFactory [collection1]  webapp=/solr path=/update 
params={waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=}
 0 21
   [junit4]   2> 62826 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.c.S.Request [collection1]  webapp=/solr path=/select 
params={facet.query={!key%3DhighPrice+tag%3Ds1}price:[100+TO+*]&facet.query={!tag%3Ds1+key%3DlowPrice}price:[0+TO+50]&q=*:*&facet.pivot={!query%3Ds1}features,manu&facet.mincount=0&rows=0&facet=true&wt=javabin&version=2}
 hits=12 status=0 QTime=37
   [junit4]   2> 62827 INFO  
(TEST-SolrExampleStreamingBinaryTest.testPivotFacetsQueries-seed#[116E48DA5F64393B])
 [    ] o.a.s.SolrTestCaseJ4 ###Ending testPivotFacetsQueries
   [junit4]   2> 62831 INFO  
(TEST-SolrExampleStreamingBinaryTest.testCommitWithinOnDelete-seed#[116E48DA5F64393B])
 [    ] o.a.s.SolrTestCaseJ4 ###Starting testCommitWithinOnDelete
   [junit4]   2> 62847 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: anyChanges? numDocsInRam=0 
deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 62847 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: anyChanges? numDocsInRam=0 
deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 62847 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: nrtIsCurrent: infoVersion 
matches: true; DW changes: true; BD changes: false
   [junit4]   2> 62847 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: flush at getReader
   [junit4]   2> 62847 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: startFullFlush
   [junit4]   2> 62847 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: anyChanges? numDocsInRam=0 
deletes=true hasTickets:false pendingChangesInFullFlush: false
   [junit4]   2> 62848 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: qtp1997229216-2210: flush 
naked frozen global deletes
   [junit4]   2> 62848 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: compressed 76 to 48 bytes 
(63.16%) for deletes/updates; private segment null
   [junit4]   2> 62848 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: push new packet (delGen=7 
numDeleteQuerys=1 bytesUsed=48), packetCount=1, bytesUsed=0.000 MB
   [junit4]   2> 62848 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][qtp1997229216-2210]: flush: push buffered 
updates: delGen=7 numDeleteQuerys=1 bytesUsed=48
   [junit4]   2> 62848 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: now apply del packet 
(delGen=7 numDeleteQuerys=1 bytesUsed=48) to 1 segments, mergeGen 0
   [junit4]   2> 62849 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: applyQueryDeletes took 1.53 
msec for 1 segments and 1 queries; 12 new deletions
   [junit4]   2> 62849 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [BD][qtp1997229216-2210]: closeSegmentStates: 12 new 
deleted documents; pool 1 packets; bytesUsed=0
   [junit4]   2> 62850 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: now checkpoint 
"_1(7.3.0):C12/12" [1 segments ; isCommit = false]
   [junit4]   2> 62850 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: 0 msec to checkpoint
   [junit4]   2> 62850 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IW][qtp1997229216-2210]: drop 100% deleted segments: 
_1(7.3.0):C12/12
   [junit4]   2> 62850 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: now checkpoint "" [0 
segments ; isCommit = false]
   [junit4]   2> 62850 INFO  (qtp1997229216-2210) [    x:collection1] 
o.a.s.u.LoggingInfoStream [IFD][qtp1997229216-2210]: 0 msec to checkpoint
   [junit4]   2> 62850 INFO  (qtp1997229216-22

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

 2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    x:collection1] 
o.a.s.u.LoggingInfoStream [DW][coreCloseExecutor-506-thread-1]: 
coreCloseExecutor-506-thread-1 finishFullFlush success=true
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-506-thread-1]: 
startCommit(): start
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-506-thread-1]:  
 skip startCommit(): no changes pending
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-506-thread-1]: 
commit: pendingCommit == null; skip
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-506-thread-1]: 
commit: took 0.3 msec
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-506-thread-1]: 
commit: done
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-506-thread-1]: 
rollback
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-506-thread-1]: 
all running merges have aborted
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-506-thread-1]: 
rollback: done finish merges
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [DW][coreCloseExecutor-506-thread-1]: 
abort
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [DW][coreCloseExecutor-506-thread-1]: 
done abort success=true
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IW][coreCloseExecutor-506-thread-1]: 
rollback: infos=_22(7.3.0):C8
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreCloseExecutor-506-thread-1]: 
now checkpoint "_22(7.3.0):C8" [1 segments ; isCommit = false]
   [junit4]   2> 69173 INFO  (coreCloseExecutor-506-thread-1) [    
x:collection1] o.a.s.u.LoggingInfoStream [IFD][coreCloseExecutor-506-thread-1]: 
0 msec to checkpoint
   [junit4]   2> 69177 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.e.j.s.h.ContextHandler Stopped 
o.e.j.s.ServletContextHandler@73a8392d{/solr,null,UNAVAILABLE}
   [junit4]   2> 69177 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.e.j.s.session Stopped scavenging
   [junit4]   2> 99176 WARN  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.e.j.u.t.QueuedThreadPool 
QueuedThreadPool@qtp1997229216{STOPPING,8<=11<=10000,i=0,q=1} Couldn't stop 
Thread[qtp1997229216-2250,5,TGRP-SolrExampleStreamingBinaryTest]
   [junit4]   2> 99176 INFO  
(SUITE-SolrExampleStreamingBinaryTest-seed#[116E48DA5F64393B]-worker) [    ] 
o.a.s.SolrTestCaseJ4 ------------------------------------------------------- 
Done waiting for tracked resources to be released
   [junit4]   2> Feb 14, 2018 2:04:04 PM 
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> WARNING: Will linger awaiting termination of 1 leaked 
thread(s).
   [junit4]   2> Feb 14, 2018 2:04:25 PM 
com.carrotsearch.randomizedtesting.ThreadLeakControl checkThreadLeaks
   [junit4]   2> SEVERE: 1 thread leaked from SUITE scope at 
org.apache.solr.client.solrj.embedded.SolrExampleStreamingBinaryTest: 
   [junit4]   2>    1) Thread[id=2250, name=qtp1997229216-2250, 
state=TIMED_WAITING, group=TGRP-SolrExampleStreamingBinaryTest]
   [junit4]   2>         at sun.misc.Unsafe.park(Native Method)
   [junit4]   2>         at 
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]   2>         at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
   [junit4]   2>         at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> Feb 14, 2018 2:04:25 PM 
com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
   [junit4]   2> INFO: Starting to interrupt leaked threads:
   [junit4]   2>    1) Thread[id=2250, name=qtp1997229216-2250, 
state=TIMED_WAITING, group=TGRP-SolrExampleStreamingBinaryTest]
   [junit4]   2> Feb 14, 2018 2:04:28 PM 
com.carrotsearch.randomizedtesting.ThreadLeakControl tryToInterruptAll
   [junit4]   2> SEVERE: There are still zombie threads that couldn't be 
terminated:
   [junit4]   2>    1) Thread[id=2250, name=qtp1997229216-2250, 
state=TIMED_WAITING, group=TGRP-SolrExampleStreamingBinaryTest]
   [junit4]   2>         at sun.misc.Unsafe.park(Native Method)
   [junit4]   2>         at 
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]   2>         at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
   [junit4]   2>         at 
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
   [junit4]   2>         at java.lang.Thread.run(Thread.java:748)
   [junit4]   2> NOTE: test params are: codec=Asserting(Lucene70): {}, 
docValues:{}, maxPointsInLeafNode=1105, maxMBSortInHeap=7.589079994378858, 
sim=RandomSimilarity(queryNorm=true): {}, locale=fi, timezone=Indian/Comoro
   [junit4]   2> NOTE: Linux 3.13.0-88-generic amd64/Oracle Corporation 
1.8.0_144 (64-bit)/cpus=4,threads=2,free=173480136,total=365953024
   [junit4]   2> NOTE: All tests run in this JVM: [StreamExpressionParserTest, 
TermsResponseTest, SchemaTest, TestZkConfigManager, AscEvaluatorTest, 
ConcurrentUpdateSolrClientBuilderTest, HyperbolicTangentEvaluatorTest, 
FieldValueEvaluatorTest, NotEvaluatorTest, CubedRootEvaluatorTest, 
AndEvaluatorTest, StreamingTest, LessThanEvaluatorTest, TestPolicy, JdbcTest, 
SquareRootEvaluatorTest, RawValueEvaluatorTest, TestToleratedUpdateError, 
TestNamedListCodec, ShardParamsTest, AnlysisResponseBaseTest, 
SolrExampleStreamingBinaryTest]
   [junit4]   2> NOTE: reproduce with: ant test  
-Dtestcase=SolrExampleStreamingBinaryTest -Dtests.seed=116E48DA5F64393B 
-Dtests.multiplier=2 -Dtests.slow=true -Dtests.locale=fi 
-Dtests.timezone=Indian/Comoro -Dtests.asserts=true -Dtests.file.encoding=UTF-8
   [junit4] ERROR   0.00s J0 | SolrExampleStreamingBinaryTest (suite) <<<
   [junit4]    > Throwable #1: 
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE 
scope at org.apache.solr.client.solrj.embedded.SolrExampleStreamingBinaryTest: 
   [junit4]    >    1) Thread[id=2250, name=qtp1997229216-2250, 
state=TIMED_WAITING, group=TGRP-SolrExampleStreamingBinaryTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at 
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]    >         at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
   [junit4]    >         at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
   [junit4]    >         at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
   [junit4]    >         at 
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
   [junit4]    >         at 
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
   [junit4]    >         at java.lang.Thread.run(Thread.java:748)
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([116E48DA5F64393B]:0)Throwable #2: 
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie 
threads that couldn't be terminated:
   [junit4]    >    1) Thread[id=2250, name=qtp1997229216-2250, 
state=TIMED_WAITING, group=TGRP-SolrExampleStreamingBinaryTest]
   [junit4]    >         at sun.misc.Unsafe.park(Native Method)
   [junit4]    >         at 
java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
   [junit4]    >         at 
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2163)
   [junit4]    >         at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.reservedWait(ReservedThreadExecutor.java:308)
   [junit4]    >         at 
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:373)
   [junit4]    >         at 
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:708)
   [junit4]    >         at 
org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:626)
   [junit4]    >         at java.lang.Thread.run(Thread.java:748)
   [junit4]    >        at 
__randomizedtesting.SeedInfo.seed([116E48DA5F64393B]:0)
   [junit4] Completed [125/146 (1!)] on J0 in 60.31s, 36 tests, 2 errors <<< 
FAILURES!

[...truncated 47622 lines...]
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@lucene.apache.org
For additional commands, e-mail: dev-h...@lucene.apache.org

Reply via email to