You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@lucene.apache.org by Policeman Jenkins Server <je...@thetaphi.de> on 2017/02/15 03:27:35 UTC
[JENKINS] Lucene-Solr-6.x-Windows (32bit/jdk1.8.0_121) - Build #
729 - Unstable!
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Windows/729/
Java: 32bit/jdk1.8.0_121 -server -XX:+UseParallelGC
1 tests failed.
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.TestCloudRecovery
Error Message:
Could not remove the following files (in the order of attempts): C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data\tlog\tlog.0000000000000000001: java.nio.file.FileSystemException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data\tlog\tlog.0000000000000000001: The process cannot access the file because it is being used by another process. C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data\tlog C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1 C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data\tlog\tlog.0000000000000000001: java.nio.file.FileSystemException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data\tlog\tlog.0000000000000000001: The process cannot access the file because it is being used by another process. C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data\tlog C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1 C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2 C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data\tlog\tlog.0000000000000000001: java.nio.file.FileSystemException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data\tlog\tlog.0000000000000000001: The process cannot access the file because it is being used by another process. C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data\tlog C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2 C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data\tlog\tlog.0000000000000000001: java.nio.file.FileSystemException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data\tlog\tlog.0000000000000000001: The process cannot access the file because it is being used by another process. C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data\tlog C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2 C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1 C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001 C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001
Stack Trace:
java.io.IOException: Could not remove the following files (in the order of attempts):
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data\tlog\tlog.0000000000000000001: java.nio.file.FileSystemException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data\tlog\tlog.0000000000000000001: The process cannot access the file because it is being used by another process.
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data\tlog
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data\tlog\tlog.0000000000000000001: java.nio.file.FileSystemException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data\tlog\tlog.0000000000000000001: The process cannot access the file because it is being used by another process.
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data\tlog
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data\tlog\tlog.0000000000000000001: java.nio.file.FileSystemException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data\tlog\tlog.0000000000000000001: The process cannot access the file because it is being used by another process.
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data\tlog
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data\tlog\tlog.0000000000000000001: java.nio.file.FileSystemException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data\tlog\tlog.0000000000000000001: The process cannot access the file because it is being used by another process.
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data\tlog
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001
C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001
at __randomizedtesting.SeedInfo.seed([88997E5D35A07074]:0)
at org.apache.lucene.util.IOUtils.rm(IOUtils.java:323)
at org.apache.lucene.util.TestRuleTemporaryFilesCleanup.afterAlways(TestRuleTemporaryFilesCleanup.java:216)
at com.carrotsearch.randomizedtesting.rules.TestRuleAdapter$1.afterAlways(TestRuleAdapter.java:31)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:43)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:745)
Build Log:
[...truncated 12571 lines...]
[junit4] Suite: org.apache.solr.cloud.TestCloudRecovery
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\init-core-data-001
[junit4] 2> 2329742 INFO (SUITE-TestCloudRecovery-seed#[88997E5D35A07074]-worker) [ ] o.a.s.SolrTestCaseJ4 Using PointFields
[junit4] 2> 2329752 INFO (SUITE-TestCloudRecovery-seed#[88997E5D35A07074]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (false) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 2329756 INFO (SUITE-TestCloudRecovery-seed#[88997E5D35A07074]-worker) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 2 servers in C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001
[junit4] 2> 2329757 INFO (SUITE-TestCloudRecovery-seed#[88997E5D35A07074]-worker) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 2329757 INFO (Thread-4356) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 2329757 INFO (Thread-4356) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 2329857 INFO (SUITE-TestCloudRecovery-seed#[88997E5D35A07074]-worker) [ ] o.a.s.c.ZkTestServer start zk server on port:58167
[junit4] 2> 2329867 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a3fb28d2a0000, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2329870 INFO (jetty-launcher-3204-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2329870 INFO (jetty-launcher-3204-thread-2) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2329872 INFO (jetty-launcher-3204-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1c6225f{/solr,null,AVAILABLE}
[junit4] 2> 2329873 INFO (jetty-launcher-3204-thread-2) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@1bae400{/solr,null,AVAILABLE}
[junit4] 2> 2329874 INFO (jetty-launcher-3204-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@16aa24b{HTTP/1.1,[http/1.1]}{127.0.0.1:58172}
[junit4] 2> 2329874 INFO (jetty-launcher-3204-thread-2) [ ] o.e.j.s.AbstractConnector Started ServerConnector@1e3badc{HTTP/1.1,[http/1.1]}{127.0.0.1:58171}
[junit4] 2> 2329877 INFO (jetty-launcher-3204-thread-2) [ ] o.e.j.s.Server Started @2335113ms
[junit4] 2> 2329877 INFO (jetty-launcher-3204-thread-1) [ ] o.e.j.s.Server Started @2335113ms
[junit4] 2> 2329877 INFO (jetty-launcher-3204-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=58172}
[junit4] 2> 2329877 INFO (jetty-launcher-3204-thread-2) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=58171}
[junit4] 2> 2329877 ERROR (jetty-launcher-3204-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2329877 ERROR (jetty-launcher-3204-thread-2) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2329877 INFO (jetty-launcher-3204-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 2329877 INFO (jetty-launcher-3204-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2329877 INFO (jetty-launcher-3204-thread-2) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 2329878 INFO (jetty-launcher-3204-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2329878 INFO (jetty-launcher-3204-thread-2) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2329878 INFO (jetty-launcher-3204-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-02-15T02:55:50.684Z
[junit4] 2> 2329878 INFO (jetty-launcher-3204-thread-2) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2329878 INFO (jetty-launcher-3204-thread-2) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-02-15T02:55:50.684Z
[junit4] 2> 2329883 INFO (jetty-launcher-3204-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2329883 INFO (jetty-launcher-3204-thread-2) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2329899 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a3fb28d2a0002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2329899 INFO (jetty-launcher-3204-thread-2) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2329899 INFO (jetty-launcher-3204-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2329899 INFO (jetty-launcher-3204-thread-2) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:58167/solr
[junit4] 2> 2329904 INFO (jetty-launcher-3204-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:58167/solr
[junit4] 2> 2329907 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a3fb28d2a0003, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2329908 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a3fb28d2a0004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2329944 INFO (jetty-launcher-3204-thread-1) [n:127.0.0.1:58172_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2329944 INFO (jetty-launcher-3204-thread-2) [n:127.0.0.1:58171_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2329945 INFO (jetty-launcher-3204-thread-2) [n:127.0.0.1:58171_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:58171_solr
[junit4] 2> 2329946 INFO (jetty-launcher-3204-thread-1) [n:127.0.0.1:58172_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58172_solr
[junit4] 2> 2329947 INFO (jetty-launcher-3204-thread-2) [n:127.0.0.1:58171_solr ] o.a.s.c.Overseer Overseer (id=97460378046955526-127.0.0.1:58171_solr-n_0000000000) starting
[junit4] 2> 2329948 INFO (zkCallback-3214-thread-1-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2329948 INFO (zkCallback-3215-thread-1-processing-n:127.0.0.1:58172_solr) [n:127.0.0.1:58172_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2329959 INFO (jetty-launcher-3204-thread-2) [n:127.0.0.1:58171_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58171_solr
[junit4] 2> 2329962 INFO (zkCallback-3215-thread-1-processing-n:127.0.0.1:58172_solr) [n:127.0.0.1:58172_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2329962 INFO (zkCallback-3214-thread-1-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (2)
[junit4] 2> 2330115 INFO (jetty-launcher-3204-thread-1) [n:127.0.0.1:58172_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\.
[junit4] 2> 2330116 INFO (jetty-launcher-3204-thread-2) [n:127.0.0.1:58171_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\.
[junit4] 2> 2330899 INFO (SUITE-TestCloudRecovery-seed#[88997E5D35A07074]-worker) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (2)
[junit4] 2> 2330900 INFO (SUITE-TestCloudRecovery-seed#[88997E5D35A07074]-worker) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:58167/solr ready
[junit4] 2> 2330913 INFO (qtp27979983-18755) [n:127.0.0.1:58171_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=2&collection.configName=config&maxShardsPerNode=2&name=collection1&action=CREATE&numShards=2&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 2330916 INFO (OverseerThreadFactory-8119-thread-1-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr ] o.a.s.c.CreateCollectionCmd Create collection collection1
[junit4] 2> 2331026 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=config&newCollection=true&name=collection1_shard1_replica2&action=CREATE&numShards=2&collection=collection1&shard=shard1&wt=javabin&version=2
[junit4] 2> 2331027 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=config&newCollection=true&name=collection1_shard2_replica2&action=CREATE&numShards=2&collection=collection1&shard=shard2&wt=javabin&version=2
[junit4] 2> 2331027 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=config&newCollection=true&name=collection1_shard1_replica1&action=CREATE&numShards=2&collection=collection1&shard=shard1&wt=javabin&version=2
[junit4] 2> 2331026 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=config&newCollection=true&name=collection1_shard2_replica1&action=CREATE&numShards=2&collection=collection1&shard=shard2&wt=javabin&version=2
[junit4] 2> 2331142 INFO (zkCallback-3214-thread-3-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2331142 INFO (zkCallback-3215-thread-1-processing-n:127.0.0.1:58172_solr) [n:127.0.0.1:58172_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2332056 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 2332057 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 2332057 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 2332072 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 2332077 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.s.IndexSchema [collection1_shard2_replica1] Schema name=minimal
[junit4] 2> 2332078 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.s.IndexSchema [collection1_shard2_replica2] Schema name=minimal
[junit4] 2> 2332083 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.s.IndexSchema [collection1_shard1_replica2] Schema name=minimal
[junit4] 2> 2332086 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2332086 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2332087 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.s.IndexSchema [collection1_shard1_replica1] Schema name=minimal
[junit4] 2> 2332087 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2332090 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2332094 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard1_replica1' using configuration from collection collection1
[junit4] 2> 2332094 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard1_replica2' using configuration from collection collection1
[junit4] 2> 2332094 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard2_replica1' using configuration from collection collection1
[junit4] 2> 2332094 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.c.SolrCore [[collection1_shard1_replica1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\.\collection1_shard1_replica1\data\]
[junit4] 2> 2332095 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.c.SolrCore [[collection1_shard2_replica1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\.\collection1_shard2_replica1\data\]
[junit4] 2> 2332095 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.c.SolrCore [[collection1_shard1_replica2] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\.\collection1_shard1_replica2\data\]
[junit4] 2> 2332107 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard2_replica2' using configuration from collection collection1
[junit4] 2> 2332113 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.c.SolrCore [[collection1_shard2_replica2] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\.\collection1_shard2_replica2\data\]
[junit4] 2> 2332302 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2332302 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2332302 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2332303 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2332304 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2332304 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2332310 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@e0e42a[collection1_shard1_replica2] main]
[junit4] 2> 2332310 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2332310 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2332311 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
[junit4] 2> 2332312 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
[junit4] 2> 2332312 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2332312 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1559366051423059968
[junit4] 2> 2332312 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.s.SolrIndexSearcher Opening [Searcher@9882e7[collection1_shard2_replica2] main]
[junit4] 2> 2332313 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
[junit4] 2> 2332314 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
[junit4] 2> 2332314 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2332314 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1559366051425157120
[junit4] 2> 2332320 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard1: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2332322 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.c.ShardLeaderElectionContext Waiting until we see more replicas up for shard shard2: total=2 found=1 timeoutin=9999ms
[junit4] 2> 2332324 INFO (searcherExecutor-8127-thread-1-processing-n:127.0.0.1:58171_solr x:collection1_shard2_replica2 s:shard2 c:collection1) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.c.SolrCore [collection1_shard2_replica2] Registered new searcher Searcher@9882e7[collection1_shard2_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2332326 INFO (searcherExecutor-8125-thread-1-processing-n:127.0.0.1:58171_solr x:collection1_shard1_replica2 s:shard1 c:collection1) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.c.SolrCore [collection1_shard1_replica2] Registered new searcher Searcher@e0e42a[collection1_shard1_replica2] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2332333 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2332333 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2332335 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2332335 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2332340 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 2332340 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir=null defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 2332341 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1b8c2a9[collection1_shard2_replica1] main]
[junit4] 2> 2332342 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 2332342 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
[junit4] 2> 2332342 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 2332342 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
[junit4] 2> 2332342 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2332342 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1559366051454517248
[junit4] 2> 2332344 INFO (searcherExecutor-8126-thread-1-processing-n:127.0.0.1:58172_solr x:collection1_shard2_replica1 s:shard2 c:collection1) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.c.SolrCore [collection1_shard2_replica1] Registered new searcher Searcher@1b8c2a9[collection1_shard2_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2332347 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@1f86ec2[collection1_shard1_replica1] main]
[junit4] 2> 2332350 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/config
[junit4] 2> 2332350 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/config
[junit4] 2> 2332350 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 2332351 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1559366051463954432
[junit4] 2> 2332351 INFO (searcherExecutor-8124-thread-1-processing-n:127.0.0.1:58172_solr x:collection1_shard1_replica1 s:shard1 c:collection1) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.c.SolrCore [collection1_shard1_replica1] Registered new searcher Searcher@1f86ec2[collection1_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 2332426 INFO (zkCallback-3215-thread-1-processing-n:127.0.0.1:58172_solr) [n:127.0.0.1:58172_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2332426 INFO (zkCallback-3214-thread-1-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2332821 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2332821 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2332822 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:58171/solr/collection1_shard1_replica2/
[junit4] 2> 2332822 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=collection1_shard1_replica2 url=http://127.0.0.1:58171/solr START replicas=[http://127.0.0.1:58172/solr/collection1_shard1_replica1/] nUpdates=100
[junit4] 2> 2332822 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 2332822 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 2332822 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.c.SyncStrategy Sync replicas to http://127.0.0.1:58171/solr/collection1_shard2_replica2/
[junit4] 2> 2332822 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.u.PeerSync PeerSync: core=collection1_shard2_replica2 url=http://127.0.0.1:58171/solr START replicas=[http://127.0.0.1:58172/solr/collection1_shard2_replica1/] nUpdates=100
[junit4] 2> 2332822 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.u.PeerSync PeerSync: core=collection1_shard1_replica2 url=http://127.0.0.1:58171/solr DONE. We have no versions. sync failed.
[junit4] 2> 2332823 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.u.PeerSync PeerSync: core=collection1_shard2_replica2 url=http://127.0.0.1:58171/solr DONE. We have no versions. sync failed.
[junit4] 2> 2332827 INFO (qtp9624590-18760) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.c.S.Request [collection1_shard1_replica1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2332827 INFO (qtp9624590-18762) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.c.S.Request [collection1_shard2_replica1] webapp=/solr path=/get params={distrib=false&qt=/get&fingerprint=false&getVersions=100&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 2332828 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2332828 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.c.SyncStrategy Leader's attempt to sync with shard failed, moving to the next candidate
[junit4] 2> 2332828 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2332828 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.c.ShardLeaderElectionContext We failed sync, but we have no versions - we can't sync in that case - we were active before, so become leader anyway
[junit4] 2> 2332832 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:58171/solr/collection1_shard1_replica2/ shard1
[junit4] 2> 2332832 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.c.ShardLeaderElectionContext I am the new leader: http://127.0.0.1:58171/solr/collection1_shard2_replica2/ shard2
[junit4] 2> 2332938 INFO (zkCallback-3214-thread-3-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2332938 INFO (zkCallback-3215-thread-1-processing-n:127.0.0.1:58172_solr) [n:127.0.0.1:58172_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2332984 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2332985 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 2332991 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 x:collection1_shard2_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=config&newCollection=true&name=collection1_shard2_replica2&action=CREATE&numShards=2&collection=collection1&shard=shard2&wt=javabin&version=2} status=0 QTime=1964
[junit4] 2> 2332993 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard1 x:collection1_shard1_replica2] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=config&newCollection=true&name=collection1_shard1_replica2&action=CREATE&numShards=2&collection=collection1&shard=shard1&wt=javabin&version=2} status=0 QTime=1966
[junit4] 2> 2333094 INFO (zkCallback-3214-thread-1-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2333094 INFO (zkCallback-3215-thread-1-processing-n:127.0.0.1:58172_solr) [n:127.0.0.1:58172_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2333354 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 x:collection1_shard2_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=config&newCollection=true&name=collection1_shard2_replica1&action=CREATE&numShards=2&collection=collection1&shard=shard2&wt=javabin&version=2} status=0 QTime=2327
[junit4] 2> 2333359 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 x:collection1_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=config&newCollection=true&name=collection1_shard1_replica1&action=CREATE&numShards=2&collection=collection1&shard=shard1&wt=javabin&version=2} status=0 QTime=2332
[junit4] 2> 2333361 INFO (qtp27979983-18755) [n:127.0.0.1:58171_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 2333460 INFO (zkCallback-3214-thread-1-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2333460 INFO (zkCallback-3215-thread-1-processing-n:127.0.0.1:58172_solr) [n:127.0.0.1:58172_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/collection1/state.json] for collection [collection1] has occurred - updating... (live nodes size: [2])
[junit4] 2> 2334362 INFO (qtp27979983-18755) [n:127.0.0.1:58171_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=2&collection.configName=config&maxShardsPerNode=2&name=collection1&action=CREATE&numShards=2&wt=javabin&version=2} status=0 QTime=3448
[junit4] 2> 2334362 INFO (SUITE-TestCloudRecovery-seed#[88997E5D35A07074]-worker) [ ] o.a.s.c.AbstractDistribZkTestBase Wait for recoveries to finish - collection: collection1 failOnTimeout:true timeout (sec):30
[junit4] 2> 2334364 INFO (SUITE-TestCloudRecovery-seed#[88997E5D35A07074]-worker) [ ] o.a.s.c.AbstractDistribZkTestBase Recoveries finished - collection: collection1
[junit4] 2> 2334386 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.SolrTestCaseJ4 ###Starting corruptedLogTest
[junit4] 2> 2334408 INFO (qtp9624590-18748) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1559366053608292352&distrib.from=http://127.0.0.1:58171/solr/collection1_shard1_replica2/&wt=javabin&version=2}{deleteByQuery=*:* (-1559366053608292352)} 0 5
[junit4] 2> 2334409 INFO (qtp27979983-18758) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica2] webapp=/solr path=/update params={update.distrib=TOLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&wt=javabin&version=2}{deleteByQuery=*:* (-1559366053608292352)} 0 12
[junit4] 2> 2334409 INFO (qtp9624590-18750) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&_version_=-1559366053606195200&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&wt=javabin&version=2}{deleteByQuery=*:* (-1559366053606195200)} 0 4
[junit4] 2> 2334409 INFO (qtp27979983-18761) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{deleteByQuery=*:* (-1559366053606195200)} 0 17
[junit4] 2> 2334413 INFO (qtp9624590-18757) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2334413 INFO (qtp9624590-18757) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2334414 INFO (qtp27979983-18752) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2334414 INFO (qtp27979983-18752) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2334414 INFO (qtp9624590-18757) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2334415 INFO (qtp9624590-18760) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2334415 INFO (qtp27979983-18752) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2334415 INFO (qtp9624590-18760) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2334416 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 2334416 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.DirectUpdateHandler2 No uncommitted changes. Skipping IW.commit.
[junit4] 2> 2334416 INFO (qtp9624590-18760) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2334416 INFO (qtp27979983-18752) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 3
[junit4] 2> 2334417 INFO (qtp9624590-18760) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 1
[junit4] 2> 2334417 INFO (qtp9624590-18757) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 4
[junit4] 2> 2334419 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 2334419 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica2] webapp=/solr path=/update params={update.distrib=FROMLEADER&waitSearcher=true&openSearcher=true&commit=true&softCommit=false&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&commit_end_point=true&wt=javabin&version=2&expungeDeletes=false}{commit=} 0 2
[junit4] 2> 2334419 INFO (qtp27979983-18763) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica2] webapp=/solr path=/update params={_stateVer_=collection1:5&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 7
[junit4] 2> 2334433 INFO (qtp9624590-18762) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard1_replica2/&wt=javabin&version=2}{add=[1000 (1559366053641846784)]} 0 2
[junit4] 2> 2334434 INFO (qtp27979983-18752) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1000 (1559366053641846784)]} 0 6
[junit4] 2> 2334443 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&wt=javabin&version=2}{add=[1001 (1559366053650235392)]} 0 2
[junit4] 2> 2334443 INFO (qtp27979983-18755) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1001 (1559366053650235392)]} 0 7
[junit4] 2> 2334446 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard1_replica2/&wt=javabin&version=2}{add=[0 (1559366053659672576)]} 0 0
[junit4] 2> 2334446 INFO (qtp27979983-18758) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[0 (1559366053659672576)]} 0 1
[junit4] 2> 2334449 INFO (qtp9624590-18748) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard1_replica2/&wt=javabin&version=2}{add=[1 (1559366053662818304)]} 0 0
[junit4] 2> 2334449 INFO (qtp27979983-18761) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[1 (1559366053662818304)]} 0 1
[junit4] 2> 2334451 INFO (qtp9624590-18750) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&wt=javabin&version=2}{add=[2 (1559366053664915456)]} 0 0
[junit4] 2> 2334451 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[2 (1559366053664915456)]} 0 1
[junit4] 2> 2334454 INFO (qtp9624590-18760) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&wt=javabin&version=2}{add=[3 (1559366053668061184)]} 0 0
[junit4] 2> 2334454 INFO (qtp27979983-18756) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[3 (1559366053668061184)]} 0 1
[junit4] 2> 2334456 INFO (qtp9624590-18757) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard1_replica2/&wt=javabin&version=2}{add=[4 (1559366053670158336)]} 0 0
[junit4] 2> 2334456 INFO (qtp27979983-18763) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[4 (1559366053670158336)]} 0 1
[junit4] 2> 2334458 INFO (qtp9624590-18762) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&wt=javabin&version=2}{add=[5 (1559366053672255488)]} 0 0
[junit4] 2> 2334459 INFO (qtp27979983-18752) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[5 (1559366053672255488)]} 0 1
[junit4] 2> 2334461 INFO (qtp9624590-18751) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&wt=javabin&version=2}{add=[6 (1559366053675401216)]} 0 0
[junit4] 2> 2334461 INFO (qtp27979983-18755) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[6 (1559366053675401216)]} 0 1
[junit4] 2> 2334464 INFO (qtp9624590-18754) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&wt=javabin&version=2}{add=[7 (1559366053678546944)]} 0 0
[junit4] 2> 2334464 INFO (qtp27979983-18758) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[7 (1559366053678546944)]} 0 1
[junit4] 2> 2334467 INFO (qtp9624590-18748) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard1_replica2/&wt=javabin&version=2}{add=[8 (1559366053681692672)]} 0 0
[junit4] 2> 2334467 INFO (qtp27979983-18761) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard1_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[8 (1559366053681692672)]} 0 1
[junit4] 2> 2334470 INFO (qtp9624590-18750) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica1] webapp=/solr path=/update params={update.distrib=FROMLEADER&distrib.from=http://127.0.0.1:58171/solr/collection1_shard2_replica2/&wt=javabin&version=2}{add=[9 (1559366053684838400)]} 0 0
[junit4] 2> 2334470 INFO (qtp27979983-18759) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.u.p.LogUpdateProcessorFactory [collection1_shard2_replica2] webapp=/solr path=/update params={wt=javabin&version=2}{add=[9 (1559366053684838400)]} 0 1
[junit4] 2> 2334474 INFO (qtp27979983-18763) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.c.S.Request [collection1_shard2_replica2] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=collection1:5&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:58171/solr/collection1_shard2_replica2/|http://127.0.0.1:58172/solr/collection1_shard2_replica1/&rows=10&version=2&q=*:*&NOW=1487127355278&isShard=true&wt=javabin} hits=0 status=0 QTime=0
[junit4] 2> 2334474 INFO (qtp9624590-18762) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.c.S.Request [collection1_shard1_replica1] webapp=/solr path=/select params={df=text&distrib=false&_stateVer_=collection1:5&fl=id&fl=score&shards.purpose=4&start=0&fsv=true&shard.url=http://127.0.0.1:58172/solr/collection1_shard1_replica1/|http://127.0.0.1:58171/solr/collection1_shard1_replica2/&rows=10&version=2&q=*:*&NOW=1487127355278&isShard=true&wt=javabin} hits=0 status=0 QTime=0
[junit4] 2> 2334474 INFO (qtp9624590-18757) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.c.S.Request [collection1_shard2_replica1] webapp=/solr path=/select params={q=*:*&_stateVer_=collection1:5&wt=javabin&version=2} hits=0 status=0 QTime=3
[junit4] 2> 2334476 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.c.ChaosMonkey monkey: stop shard! 58171
[junit4] 2> 2334476 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=4580256
[junit4] 2> 2334478 INFO (coreCloseExecutor-8144-thread-2) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.c.SolrCore [collection1_shard2_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@29d609
[junit4] 2> 2334480 INFO (coreCloseExecutor-8144-thread-1) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.c.SolrCore [collection1_shard1_replica2] CLOSING SolrCore org.apache.solr.core.SolrCore@1e816e3
[junit4] 2> 2334482 INFO (coreCloseExecutor-8144-thread-1) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1.shard1.replica2
[junit4] 2> 2334482 INFO (coreCloseExecutor-8144-thread-2) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1.shard2.replica2
[junit4] 2> 2334485 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.c.Overseer Overseer (id=97460378046955526-127.0.0.1:58171_solr-n_0000000000) closing
[junit4] 2> 2334485 INFO (OverseerStateUpdate-97460378046955526-127.0.0.1:58171_solr-n_0000000000) [n:127.0.0.1:58171_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:58171_solr
[junit4] 2> 2334487 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a3fb28d2a0006, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2334487 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 2334488 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@1e3badc{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 2334489 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1bae400{/solr,null,UNAVAILABLE}
[junit4] 2> 2334490 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.c.ChaosMonkey monkey: stop shard! 58172
[junit4] 2> 2334490 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.c.CoreContainer Shutting down CoreContainer instance=3345373
[junit4] 2> 2334493 INFO (zkCallback-3221-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 2334493 INFO (zkCallback-3215-thread-4-processing-n:127.0.0.1:58172_solr) [n:127.0.0.1:58172_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (2) -> (1)
[junit4] 2> 2334493 INFO (zkCallback-3215-thread-2-processing-n:127.0.0.1:58172_solr) [n:127.0.0.1:58172_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:58172_solr
[junit4] 2> 2334497 INFO (zkCallback-3215-thread-2-processing-n:127.0.0.1:58172_solr) [n:127.0.0.1:58172_solr ] o.a.s.c.Overseer Overseer (id=97460378046955525-127.0.0.1:58172_solr-n_0000000001) starting
[junit4] 2> 2334497 INFO (coreCloseExecutor-8146-thread-1) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.c.SolrCore [collection1_shard2_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@1089320
[junit4] 2> 2334497 INFO (coreCloseExecutor-8146-thread-2) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.c.SolrCore [collection1_shard1_replica1] CLOSING SolrCore org.apache.solr.core.SolrCore@1385333
[junit4] 2> 2334500 INFO (coreCloseExecutor-8146-thread-2) [n:127.0.0.1:58172_solr c:collection1 s:shard1 r:core_node2 x:collection1_shard1_replica1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1.shard1.replica1
[junit4] 2> 2334503 INFO (coreCloseExecutor-8146-thread-1) [n:127.0.0.1:58172_solr c:collection1 s:shard2 r:core_node3 x:collection1_shard2_replica1] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.core.collection1.shard2.replica1
[junit4] 2> 2334505 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.c.Overseer Overseer (id=97460378046955525-127.0.0.1:58172_solr-n_0000000001) closing
[junit4] 2> 2334506 INFO (OverseerCollectionConfigSetProcessor-97460378046955525-127.0.0.1:58172_solr-n_0000000001) [n:127.0.0.1:58172_solr ] o.a.s.c.OverseerTaskProcessor According to ZK I (id=97460378046955525-127.0.0.1:58172_solr-n_0000000001) am no longer a leader.
[junit4] 2> 2334506 ERROR (OverseerCollectionConfigSetProcessor-97460378046955525-127.0.0.1:58172_solr-n_0000000001) [n:127.0.0.1:58172_solr ] o.a.s.c.OverseerTaskProcessor Unable to prioritize overseer
[junit4] 2> java.lang.InterruptedException
[junit4] 2> at java.lang.Object.wait(Native Method)
[junit4] 2> at java.lang.Object.wait(Object.java:502)
[junit4] 2> at org.apache.zookeeper.ClientCnxn.submitRequest(ClientCnxn.java:1342)
[junit4] 2> at org.apache.zookeeper.ZooKeeper.exists(ZooKeeper.java:1040)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:322)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient$5.execute(SolrZkClient.java:319)
[junit4] 2> at org.apache.solr.common.cloud.ZkCmdExecutor.retryOperation(ZkCmdExecutor.java:60)
[junit4] 2> at org.apache.solr.common.cloud.SolrZkClient.exists(SolrZkClient.java:319)
[junit4] 2> at org.apache.solr.cloud.OverseerNodePrioritizer.prioritizeOverseerNodes(OverseerNodePrioritizer.java:60)
[junit4] 2> at org.apache.solr.cloud.OverseerTaskProcessor.run(OverseerTaskProcessor.java:177)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2334507 INFO (OverseerStateUpdate-97460378046955525-127.0.0.1:58172_solr-n_0000000001) [n:127.0.0.1:58172_solr ] o.a.s.c.Overseer According to ZK I (id=97460378046955525-127.0.0.1:58172_solr-n_0000000001) am no longer a leader.
[junit4] 2> 2334526 INFO (OverseerStateUpdate-97460378046955525-127.0.0.1:58172_solr-n_0000000001) [n:127.0.0.1:58172_solr ] o.a.s.c.Overseer Overseer Loop exiting : 127.0.0.1:58172_solr
[junit4] 2> 2334527 WARN (zkCallback-3215-thread-2-processing-n:127.0.0.1:58172_solr) [n:127.0.0.1:58172_solr ] o.a.s.c.c.ZkStateReader ZooKeeper watch triggered, but Solr cannot talk to ZK: [KeeperErrorCode = Session expired for /live_nodes]
[junit4] 2> 2334528 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a3fb28d2a0005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2334528 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.m.SolrMetricManager Closing metric reporters for: solr.node
[junit4] 2> 2334529 INFO (zkCallback-3221-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (1) -> (0)
[junit4] 2> 2334529 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.e.j.s.AbstractConnector Stopped ServerConnector@16aa24b{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 2334530 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.e.j.s.h.ContextHandler Stopped o.e.j.s.ServletContextHandler@1c6225f{/solr,null,UNAVAILABLE}
[junit4] 2> 2334536 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 2334537 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@57b885{/solr,null,AVAILABLE}
[junit4] 2> 2334538 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.e.j.s.AbstractConnector Started ServerConnector@15128c6{HTTP/1.1,[http/1.1]}{127.0.0.1:58171}
[junit4] 2> 2334539 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.e.j.s.Server Started @2339774ms
[junit4] 2> 2334539 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=58171}
[junit4] 2> 2334539 ERROR (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 2334539 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 2334539 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 2334539 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 2334539 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-02-15T02:55:55.345Z
[junit4] 2> 2334542 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 2334559 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 2334560 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:58167/solr
[junit4] 2> 2334563 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a3fb28d2a000a, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 2334577 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [n:127.0.0.1:58171_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 2334578 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [n:127.0.0.1:58171_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:58171_solr
[junit4] 2> 2334579 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [n:127.0.0.1:58171_solr ] o.a.s.c.Overseer Overseer (id=97460378046955531-127.0.0.1:58171_solr-n_0000000002) starting
[junit4] 2> 2334587 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [n:127.0.0.1:58171_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:58171_solr
[junit4] 2> 2334589 INFO (zkCallback-3221-thread-1) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2334589 INFO (OverseerStateUpdate-97460378046955531-127.0.0.1:58171_solr-n_0000000002) [n:127.0.0.1:58171_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 2334766 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [n:127.0.0.1:58171_solr ] o.a.s.c.CorePropertiesLocator Found 2 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\.
[junit4] 2> 2334766 INFO (TEST-TestCloudRecovery.corruptedLogTest-seed#[88997E5D35A07074]) [n:127.0.0.1:58171_solr ] o.a.s.c.CorePropertiesLocator Cores are: [collection1_shard1_replica2, collection1_shard2_replica2]
[junit4] 2> 2334797 INFO (coreLoadExecutor-8157-thread-2-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 2334802 INFO (coreLoadExecutor-8157-thread-1-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 2334809 INFO (coreLoadExecutor-8157-thread-2-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.s.IndexSchema [collection1_shard2_replica2] Schema name=minimal
[junit4] 2> 2334812 INFO (coreLoadExecutor-8157-thread-1-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.s.IndexSchema [collection1_shard1_replica2] Schema name=minimal
[junit4] 2> 2334817 INFO (coreLoadExecutor-8157-thread-1-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2334818 INFO (coreLoadExecutor-8157-thread-2-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 2334825 INFO (coreLoadExecutor-8157-thread-1-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard1_replica2' using configuration from collection collection1
[junit4] 2> 2334825 INFO (coreLoadExecutor-8157-thread-2-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:collection1_shard2_replica2] o.a.s.c.CoreContainer Creating SolrCore 'collection1_shard2_replica2' using configuration from collection collection1
[junit4] 2> 2334825 INFO (coreLoadExecutor-8157-thread-1-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr c:collection1 s:shard1 r:core_node1 x:collection1_shard1_replica2] o.a.s.c.SolrCore [[collection1_shard1_replica2] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\.\collection1_shard1_replica2\data\]
[junit4] 2> 2334826 INFO (coreLoadExecutor-8157-thread-2-processing-n:127.0.0.1:58171_solr) [n:127.0.0.1:58171_solr c:collection1 s:shard2 r:core_node4 x:coll
[...truncated too long message...]
, DeleteNodeTest, DistribCursorPagingTest, DistributedQueueTest, DistributedVersionInfoTest, MultiThreadedOCPTest, OverriddenZkACLAndCredentialsProvidersTest, OverseerCollectionConfigSetProcessorTest, OverseerStatusTest, PeerSyncReplicationTest, TestCloudInspectUtil, TestCloudPseudoReturnFields, TestCloudRecovery]
[junit4] 2> NOTE: reproduce with: ant test -Dtestcase=TestCloudRecovery -Dtests.seed=88997E5D35A07074 -Dtests.slow=true -Dtests.locale=sr -Dtests.timezone=SystemV/CST6CDT -Dtests.asserts=true -Dtests.file.encoding=US-ASCII
[junit4] ERROR 0.00s J0 | TestCloudRecovery (suite) <<<
[junit4] > Throwable #1: java.io.IOException: Could not remove the following files (in the order of attempts):
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data\tlog\tlog.0000000000000000001: java.nio.file.FileSystemException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data\tlog\tlog.0000000000000000001: The process cannot access the file because it is being used by another process.
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data\tlog
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1\data
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard2_replica1
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data\tlog\tlog.0000000000000000001: java.nio.file.FileSystemException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data\tlog\tlog.0000000000000000001: The process cannot access the file because it is being used by another process.
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data\tlog
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1\data
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2\collection1_shard1_replica1
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node2
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data\tlog\tlog.0000000000000000001: java.nio.file.FileSystemException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data\tlog\tlog.0000000000000000001: The process cannot access the file because it is being used by another process.
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data\tlog
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2\data
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard2_replica2
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data\tlog\tlog.0000000000000000001: java.nio.file.FileSystemException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data\tlog\tlog.0000000000000000001: The process cannot access the file because it is being used by another process.
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data\tlog: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data\tlog
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2\data
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1\collection1_shard1_replica2
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001\node1
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001\tempDir-001
[junit4] > C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001: java.nio.file.DirectoryNotEmptyException: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.TestCloudRecovery_88997E5D35A07074-001
[junit4] > at __randomizedtesting.SeedInfo.seed([88997E5D35A07074]:0)
[junit4] > at org.apache.lucene.util.IOUtils.rm(IOUtils.java:323)
[junit4] > at java.lang.Thread.run(Thread.java:745)
[junit4] Completed [510/692 (1!)] on J0 in 31.63s, 2 tests, 1 error <<< FAILURES!
[...truncated 55475 lines...]
[JENKINS] Lucene-Solr-6.x-Windows (64bit/jdk1.8.0_121) - Build #
730 - Still Unstable!
Posted by Policeman Jenkins Server <je...@thetaphi.de>.
Build: https://jenkins.thetaphi.de/job/Lucene-Solr-6.x-Windows/730/
Java: 64bit/jdk1.8.0_121 -XX:+UseCompressedOops -XX:+UseG1GC
6 tests failed.
FAILED: org.apache.solr.handler.dataimport.TestContentStreamDataSource.testCommitWithin
Error Message:
expected:<0> but was:<2>
Stack Trace:
java.lang.AssertionError: expected:<0> but was:<2>
at __randomizedtesting.SeedInfo.seed([1B165D26DAB485F1:A1C4325E599A6BE4]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.failNotEquals(Assert.java:647)
at org.junit.Assert.assertEquals(Assert.java:128)
at org.junit.Assert.assertEquals(Assert.java:472)
at org.junit.Assert.assertEquals(Assert.java:456)
at org.apache.solr.handler.dataimport.TestContentStreamDataSource.testCommitWithin(TestContentStreamDataSource.java:98)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:745)
FAILED: org.apache.solr.cloud.CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap
Error Message:
Captured an uncaught exception in thread: Thread[id=3641, name=Thread-964, state=RUNNABLE, group=TGRP-CdcrBootstrapTest]
Stack Trace:
com.carrotsearch.randomizedtesting.UncaughtExceptionError: Captured an uncaught exception in thread: Thread[id=3641, name=Thread-964, state=RUNNABLE, group=TGRP-CdcrBootstrapTest]
at __randomizedtesting.SeedInfo.seed([A4EFB40B6DDF243:DD99D43702826A04]:0)
Caused by: java.lang.AssertionError: 1
at __randomizedtesting.SeedInfo.seed([A4EFB40B6DDF243]:0)
at org.apache.solr.core.CachingDirectoryFactory.close(CachingDirectoryFactory.java:191)
at org.apache.solr.core.MetricsDirectoryFactory.close(MetricsDirectoryFactory.java:117)
at org.apache.solr.core.SolrCore.close(SolrCore.java:1529)
at org.apache.solr.core.CoreContainer.registerCore(CoreContainer.java:766)
at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1097)
at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:781)
at java.lang.Thread.run(Thread.java:745)
FAILED: junit.framework.TestSuite.org.apache.solr.cloud.CdcrBootstrapTest
Error Message:
ObjectTracker found 5 object(s) that were not released!!! [MockDirectoryWrapper, SolrCore, MockDirectoryWrapper, MockDirectoryWrapper, MockDirectoryWrapper] org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:347) at org.apache.solr.core.MetricsDirectoryFactory.get(MetricsDirectoryFactory.java:214) at org.apache.solr.core.SolrCore.initSnapshotMetaDataManager(SolrCore.java:479) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:888) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:811) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:904) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:840) at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:88) at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:378) at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:388) at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174) at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:171) at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:748) at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729) at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:347) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:298) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:110) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:395) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) at org.eclipse.jetty.server.Server.handle(Server.java:534) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) at java.lang.Thread.run(Thread.java:745) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:984) at org.apache.solr.core.SolrCore.reload(SolrCore.java:637) at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1096) at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:781) at java.lang.Thread.run(Thread.java:745) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:347) at org.apache.solr.core.MetricsDirectoryFactory.get(MetricsDirectoryFactory.java:214) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:373) at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:254) at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:399) at org.apache.solr.handler.CdcrRequestHandler$BootstrapCallable.call(CdcrRequestHandler.java:757) at org.apache.solr.handler.CdcrRequestHandler$BootstrapCallable.call(CdcrRequestHandler.java:712) at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:347) at org.apache.solr.core.MetricsDirectoryFactory.get(MetricsDirectoryFactory.java:214) at org.apache.solr.update.SolrIndexWriter.create(SolrIndexWriter.java:98) at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:709) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:894) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:811) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:904) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:840) at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:88) at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:378) at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:388) at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174) at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:171) at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:748) at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729) at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:347) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:298) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:110) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:395) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) at org.eclipse.jetty.server.Server.handle(Server.java:534) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) at java.lang.Thread.run(Thread.java:745) org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42) at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:347) at org.apache.solr.core.MetricsDirectoryFactory.get(MetricsDirectoryFactory.java:214) at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:348) at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:677) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:894) at org.apache.solr.core.SolrCore.<init>(SolrCore.java:811) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:904) at org.apache.solr.core.CoreContainer.create(CoreContainer.java:840) at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:88) at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:378) at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:388) at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174) at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:171) at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:748) at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729) at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:347) at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:298) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:110) at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699) at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582) at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224) at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180) at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512) at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112) at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:395) at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134) at org.eclipse.jetty.server.Server.handle(Server.java:534) at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320) at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202) at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273) at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95) at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148) at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136) at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671) at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589) at java.lang.Thread.run(Thread.java:745)
Stack Trace:
java.lang.AssertionError: ObjectTracker found 5 object(s) that were not released!!! [MockDirectoryWrapper, SolrCore, MockDirectoryWrapper, MockDirectoryWrapper, MockDirectoryWrapper]
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:347)
at org.apache.solr.core.MetricsDirectoryFactory.get(MetricsDirectoryFactory.java:214)
at org.apache.solr.core.SolrCore.initSnapshotMetaDataManager(SolrCore.java:479)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:888)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:811)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:904)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:840)
at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:88)
at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:378)
at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:388)
at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174)
at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:171)
at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:748)
at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729)
at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:347)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:298)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:110)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:395)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
at org.eclipse.jetty.server.Server.handle(Server.java:534)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
at java.lang.Thread.run(Thread.java:745)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:984)
at org.apache.solr.core.SolrCore.reload(SolrCore.java:637)
at org.apache.solr.core.CoreContainer.reload(CoreContainer.java:1096)
at org.apache.solr.handler.IndexFetcher.lambda$reloadCore$0(IndexFetcher.java:781)
at java.lang.Thread.run(Thread.java:745)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:347)
at org.apache.solr.core.MetricsDirectoryFactory.get(MetricsDirectoryFactory.java:214)
at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:373)
at org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:254)
at org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:399)
at org.apache.solr.handler.CdcrRequestHandler$BootstrapCallable.call(CdcrRequestHandler.java:757)
at org.apache.solr.handler.CdcrRequestHandler$BootstrapCallable.call(CdcrRequestHandler.java:712)
at com.codahale.metrics.InstrumentedExecutorService$InstrumentedCallable.call(InstrumentedExecutorService.java:197)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at org.apache.solr.common.util.ExecutorUtil$MDCAwareThreadPoolExecutor.lambda$execute$0(ExecutorUtil.java:229)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:347)
at org.apache.solr.core.MetricsDirectoryFactory.get(MetricsDirectoryFactory.java:214)
at org.apache.solr.update.SolrIndexWriter.create(SolrIndexWriter.java:98)
at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:709)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:894)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:811)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:904)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:840)
at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:88)
at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:378)
at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:388)
at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174)
at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:171)
at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:748)
at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729)
at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:347)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:298)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:110)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:395)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
at org.eclipse.jetty.server.Server.handle(Server.java:534)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
at java.lang.Thread.run(Thread.java:745)
org.apache.solr.common.util.ObjectReleaseTracker$ObjectTrackerException
at org.apache.solr.common.util.ObjectReleaseTracker.track(ObjectReleaseTracker.java:42)
at org.apache.solr.core.CachingDirectoryFactory.get(CachingDirectoryFactory.java:347)
at org.apache.solr.core.MetricsDirectoryFactory.get(MetricsDirectoryFactory.java:214)
at org.apache.solr.core.SolrCore.getNewIndexDir(SolrCore.java:348)
at org.apache.solr.core.SolrCore.initIndex(SolrCore.java:677)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:894)
at org.apache.solr.core.SolrCore.<init>(SolrCore.java:811)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:904)
at org.apache.solr.core.CoreContainer.create(CoreContainer.java:840)
at org.apache.solr.handler.admin.CoreAdminOperation.lambda$static$0(CoreAdminOperation.java:88)
at org.apache.solr.handler.admin.CoreAdminOperation.execute(CoreAdminOperation.java:378)
at org.apache.solr.handler.admin.CoreAdminHandler$CallInfo.call(CoreAdminHandler.java:388)
at org.apache.solr.handler.admin.CoreAdminHandler.handleRequestBody(CoreAdminHandler.java:174)
at org.apache.solr.handler.RequestHandlerBase.handleRequest(RequestHandlerBase.java:171)
at org.apache.solr.servlet.HttpSolrCall.handleAdmin(HttpSolrCall.java:748)
at org.apache.solr.servlet.HttpSolrCall.handleAdminRequest(HttpSolrCall.java:729)
at org.apache.solr.servlet.HttpSolrCall.call(HttpSolrCall.java:510)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:347)
at org.apache.solr.servlet.SolrDispatchFilter.doFilter(SolrDispatchFilter.java:298)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
at org.apache.solr.client.solrj.embedded.JettySolrRunner$DebugFilter.doFilter(JettySolrRunner.java:110)
at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1699)
at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:224)
at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:395)
at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
at org.eclipse.jetty.server.Server.handle(Server.java:534)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:202)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:273)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:95)
at org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
at org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
at java.lang.Thread.run(Thread.java:745)
at __randomizedtesting.SeedInfo.seed([A4EFB40B6DDF243]:0)
at org.junit.Assert.fail(Assert.java:93)
at org.junit.Assert.assertTrue(Assert.java:43)
at org.junit.Assert.assertNull(Assert.java:551)
at org.apache.solr.SolrTestCaseJ4.teardownTestCases(SolrTestCaseJ4.java:301)
at sun.reflect.GeneratedMethodAccessor23.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:870)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:745)
FAILED: org.apache.solr.core.TestLazyCores.testNoCommit
Error Message:
Exception during query
Stack Trace:
java.lang.RuntimeException: Exception during query
at __randomizedtesting.SeedInfo.seed([A4EFB40B6DDF243:D52E5A917DFA91E6]:0)
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:918)
at org.apache.solr.core.TestLazyCores.check10(TestLazyCores.java:794)
at org.apache.solr.core.TestLazyCores.testNoCommit(TestLazyCores.java:776)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:498)
at com.carrotsearch.randomizedtesting.RandomizedRunner.invoke(RandomizedRunner.java:1713)
at com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:907)
at com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:943)
at com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:957)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:817)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:468)
at com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:916)
at com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:802)
at com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:852)
at com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:863)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
at org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
at org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
at org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
at org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
at com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
at com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:368)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: REQUEST FAILED: xpath=//result[@numFound='10']
xml response was: <?xml version="1.0" encoding="UTF-8"?>
<response>
<lst name="responseHeader">
<int name="status">0</int>
<int name="QTime">6</int>
<lst name="params">
<str name="q">*:*</str>
</lst>
</lst>
<result name="response" numFound="0" start="0">
</result>
</response>
request was:q=*:*
at org.apache.solr.SolrTestCaseJ4.assertQ(SolrTestCaseJ4.java:911)
... 41 more
FAILED: junit.framework.TestSuite.org.apache.solr.core.TestLazyCores
Error Message:
1 thread leaked from SUITE scope at org.apache.solr.core.TestLazyCores: 1) Thread[id=7581, name=searcherExecutor-3107-thread-1, state=WAITING, group=TGRP-TestLazyCores] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: 1 thread leaked from SUITE scope at org.apache.solr.core.TestLazyCores:
1) Thread[id=7581, name=searcherExecutor-3107-thread-1, state=WAITING, group=TGRP-TestLazyCores]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at __randomizedtesting.SeedInfo.seed([A4EFB40B6DDF243]:0)
FAILED: junit.framework.TestSuite.org.apache.solr.core.TestLazyCores
Error Message:
There are still zombie threads that couldn't be terminated: 1) Thread[id=7581, name=searcherExecutor-3107-thread-1, state=WAITING, group=TGRP-TestLazyCores] at sun.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039) at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745)
Stack Trace:
com.carrotsearch.randomizedtesting.ThreadLeakError: There are still zombie threads that couldn't be terminated:
1) Thread[id=7581, name=searcherExecutor-3107-thread-1, state=WAITING, group=TGRP-TestLazyCores]
at sun.misc.Unsafe.park(Native Method)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
at __randomizedtesting.SeedInfo.seed([A4EFB40B6DDF243]:0)
Build Log:
[...truncated 11499 lines...]
[junit4] Suite: org.apache.solr.cloud.CdcrBootstrapTest
[junit4] 2> Creating dataDir: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_A4EFB40B6DDF243-001\init-core-data-001
[junit4] 2> 540684 INFO (SUITE-CdcrBootstrapTest-seed#[A4EFB40B6DDF243]-worker) [ ] o.a.s.SolrTestCaseJ4 Using TrieFields
[junit4] 2> 540690 INFO (SUITE-CdcrBootstrapTest-seed#[A4EFB40B6DDF243]-worker) [ ] o.a.s.SolrTestCaseJ4 Randomized ssl (true) and clientAuth (false) via: @org.apache.solr.util.RandomizeSSL(reason=, value=NaN, ssl=NaN, clientAuth=NaN)
[junit4] 2> 540692 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[A4EFB40B6DDF243]) [ ] o.a.s.SolrTestCaseJ4 ###Starting testConvertClusterToCdcrAndBootstrap
[junit4] 2> 540694 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[A4EFB40B6DDF243]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_A4EFB40B6DDF243-001\cdcr-target-001
[junit4] 2> 540695 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[A4EFB40B6DDF243]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 540695 INFO (Thread-930) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 540695 INFO (Thread-930) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 540796 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[A4EFB40B6DDF243]) [ ] o.a.s.c.ZkTestServer start zk server on port:57872
[junit4] 2> 540810 INFO (jetty-launcher-530-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 540810 INFO (jetty-launcher-530-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@79b4a26a{/solr,null,AVAILABLE}
[junit4] 2> 540815 INFO (jetty-launcher-530-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@55db81bb{SSL,[ssl, http/1.1]}{127.0.0.1:57876}
[junit4] 2> 540815 INFO (jetty-launcher-530-thread-1) [ ] o.e.j.s.Server Started @545887ms
[junit4] 2> 540815 INFO (jetty-launcher-530-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57876}
[junit4] 2> 540816 ERROR (jetty-launcher-530-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 540816 INFO (jetty-launcher-530-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 540816 INFO (jetty-launcher-530-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 540816 INFO (jetty-launcher-530-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 540816 INFO (jetty-launcher-530-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-02-15T17:27:49.309Z
[junit4] 2> 540820 INFO (jetty-launcher-530-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 540838 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a42d0deca0001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 540843 INFO (jetty-launcher-530-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 540844 INFO (jetty-launcher-530-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57872/solr
[junit4] 2> 540847 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a42d0deca0002, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 540875 INFO (jetty-launcher-530-thread-1) [n:127.0.0.1:57876_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 540876 INFO (jetty-launcher-530-thread-1) [n:127.0.0.1:57876_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:57876_solr
[junit4] 2> 540878 INFO (jetty-launcher-530-thread-1) [n:127.0.0.1:57876_solr ] o.a.s.c.Overseer Overseer (id=97463806800297987-127.0.0.1:57876_solr-n_0000000000) starting
[junit4] 2> 540887 INFO (jetty-launcher-530-thread-1) [n:127.0.0.1:57876_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57876_solr
[junit4] 2> 540889 INFO (OverseerStateUpdate-97463806800297987-127.0.0.1:57876_solr-n_0000000000) [n:127.0.0.1:57876_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 541068 INFO (jetty-launcher-530-thread-1) [n:127.0.0.1:57876_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_A4EFB40B6DDF243-001\cdcr-target-001\node1\.
[junit4] 2> 541144 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a42d0deca0004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 541147 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a42d0deca0005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 1> Target zkHost = 127.0.0.1:57872/solr
[junit4] 2> 541151 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[A4EFB40B6DDF243]) [ ] o.a.s.c.MiniSolrCloudCluster Starting cluster of 1 servers in C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_A4EFB40B6DDF243-001\cdcr-source-001
[junit4] 2> 541151 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[A4EFB40B6DDF243]) [ ] o.a.s.c.ZkTestServer STARTING ZK TEST SERVER
[junit4] 2> 541151 INFO (Thread-940) [ ] o.a.s.c.ZkTestServer client port:0.0.0.0/0.0.0.0:0
[junit4] 2> 541151 INFO (Thread-940) [ ] o.a.s.c.ZkTestServer Starting server
[junit4] 2> 541155 WARN (Thread-940) [ ] o.a.z.j.MBeanRegistry Failed to register MBean StandaloneServer_port-1
[junit4] 2> 541157 WARN (Thread-940) [ ] o.a.z.s.ZooKeeperServer Failed to register with JMX
[junit4] 2> javax.management.InstanceAlreadyExistsException: org.apache.ZooKeeperService:name0=StandaloneServer_port-1
[junit4] 2> at com.sun.jmx.mbeanserver.Repository.addMBean(Repository.java:437)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerWithRepository(DefaultMBeanServerInterceptor.java:1898)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerDynamicMBean(DefaultMBeanServerInterceptor.java:966)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerObject(DefaultMBeanServerInterceptor.java:900)
[junit4] 2> at com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.registerMBean(DefaultMBeanServerInterceptor.java:324)
[junit4] 2> at com.sun.jmx.mbeanserver.JmxMBeanServer.registerMBean(JmxMBeanServer.java:522)
[junit4] 2> at org.apache.zookeeper.jmx.MBeanRegistry.register(MBeanRegistry.java:96)
[junit4] 2> at org.apache.zookeeper.server.ZooKeeperServer.registerJMX(ZooKeeperServer.java:377)
[junit4] 2> at org.apache.zookeeper.server.ZooKeeperServer.startup(ZooKeeperServer.java:410)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.startup(NIOServerCnxnFactory.java:123)
[junit4] 2> at org.apache.solr.cloud.ZkTestServer$ZKServerMain.runFromConfig(ZkTestServer.java:308)
[junit4] 2> at org.apache.solr.cloud.ZkTestServer$2.run(ZkTestServer.java:490)
[junit4] 2> 541251 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[A4EFB40B6DDF243]) [ ] o.a.s.c.ZkTestServer start zk server on port:57896
[junit4] 2> 541276 INFO (jetty-launcher-541-thread-1) [ ] o.e.j.s.Server jetty-9.3.14.v20161028
[junit4] 2> 541277 INFO (jetty-launcher-541-thread-1) [ ] o.e.j.s.h.ContextHandler Started o.e.j.s.ServletContextHandler@43f8e068{/solr,null,AVAILABLE}
[junit4] 2> 541278 INFO (jetty-launcher-541-thread-1) [ ] o.e.j.s.AbstractConnector Started ServerConnector@508b7073{SSL,[ssl, http/1.1]}{127.0.0.1:57900}
[junit4] 2> 541278 INFO (jetty-launcher-541-thread-1) [ ] o.e.j.s.Server Started @546350ms
[junit4] 2> 541278 INFO (jetty-launcher-541-thread-1) [ ] o.a.s.c.s.e.JettySolrRunner Jetty properties: {hostContext=/solr, hostPort=57900}
[junit4] 2> 541278 ERROR (jetty-launcher-541-thread-1) [ ] o.a.s.s.StartupLoggingUtils Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 541278 INFO (jetty-launcher-541-thread-1) [ ] o.a.s.s.SolrDispatchFilter ___ _ Welcome to Apache Solr? version 6.5.0
[junit4] 2> 541278 INFO (jetty-launcher-541-thread-1) [ ] o.a.s.s.SolrDispatchFilter / __| ___| |_ _ Starting in cloud mode on port null
[junit4] 2> 541278 INFO (jetty-launcher-541-thread-1) [ ] o.a.s.s.SolrDispatchFilter \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 541278 INFO (jetty-launcher-541-thread-1) [ ] o.a.s.s.SolrDispatchFilter |___/\___/_|_| Start time: 2017-02-15T17:27:49.771Z
[junit4] 2> 541282 INFO (jetty-launcher-541-thread-1) [ ] o.a.s.s.SolrDispatchFilter solr.xml found in ZooKeeper. Loading...
[junit4] 2> 541295 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a42d0e0900001, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 541300 INFO (jetty-launcher-541-thread-1) [ ] o.a.s.u.UpdateShardHandler Creating UpdateShardHandler HTTP client with params: socketTimeout=340000&connTimeout=45000&retry=true
[junit4] 2> 541301 INFO (jetty-launcher-541-thread-1) [ ] o.a.s.c.ZkContainer Zookeeper client=127.0.0.1:57896/solr
[junit4] 2> 541333 INFO (jetty-launcher-541-thread-1) [n:127.0.0.1:57900_solr ] o.a.s.c.Overseer Overseer (id=null) closing
[junit4] 2> 541334 INFO (jetty-launcher-541-thread-1) [n:127.0.0.1:57900_solr ] o.a.s.c.OverseerElectionContext I am going to be the leader 127.0.0.1:57900_solr
[junit4] 2> 541336 INFO (jetty-launcher-541-thread-1) [n:127.0.0.1:57900_solr ] o.a.s.c.Overseer Overseer (id=97463806830051331-127.0.0.1:57900_solr-n_0000000000) starting
[junit4] 2> 541344 INFO (jetty-launcher-541-thread-1) [n:127.0.0.1:57900_solr ] o.a.s.c.ZkController Register node as live in ZooKeeper:/live_nodes/127.0.0.1:57900_solr
[junit4] 2> 541351 INFO (zkCallback-547-thread-1-processing-n:127.0.0.1:57900_solr) [n:127.0.0.1:57900_solr ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 541496 INFO (jetty-launcher-541-thread-1) [n:127.0.0.1:57900_solr ] o.a.s.c.CorePropertiesLocator Found 0 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_A4EFB40B6DDF243-001\cdcr-source-001\node1\.
[junit4] 2> 541563 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a42d0e0900004, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 541567 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a42d0e0900005, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 541577 WARN (NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0) [ ] o.a.z.s.NIOServerCnxn caught end of stream exception
[junit4] 2> EndOfStreamException: Unable to read additional data from client sessionid 0x15a42d0e0900006, likely client has closed socket
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxn.doIO(NIOServerCnxn.java:228)
[junit4] 2> at org.apache.zookeeper.server.NIOServerCnxnFactory.run(NIOServerCnxnFactory.java:208)
[junit4] 2> at java.lang.Thread.run(Thread.java:745)
[junit4] 2> 541582 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[A4EFB40B6DDF243]) [ ] o.a.s.c.c.ZkStateReader Updated live nodes from ZooKeeper... (0) -> (1)
[junit4] 2> 541583 INFO (TEST-CdcrBootstrapTest.testConvertClusterToCdcrAndBootstrap-seed#[A4EFB40B6DDF243]) [ ] o.a.s.c.s.i.ZkClientClusterStateProvider Cluster at 127.0.0.1:57896/solr ready
[junit4] 2> 541607 INFO (qtp789717658-3521) [n:127.0.0.1:57900_solr ] o.a.s.h.a.CollectionsHandler Invoked Collection Action :create with params replicationFactor=1&collection.configName=cdcr-source&name=cdcr-source&action=CREATE&numShards=1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2 and sendToOCPQueue=true
[junit4] 2> 541611 INFO (OverseerThreadFactory-1268-thread-1-processing-n:127.0.0.1:57900_solr) [n:127.0.0.1:57900_solr ] o.a.s.c.CreateCollectionCmd Create collection cdcr-source
[junit4] 2> 541722 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr ] o.a.s.h.a.CoreAdminOperation core create command qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&name=cdcr-source_shard1_replica1&action=CREATE&numShards=1&collection=cdcr-source&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2
[junit4] 2> 541833 INFO (zkCallback-547-thread-1-processing-n:127.0.0.1:57900_solr) [n:127.0.0.1:57900_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 542751 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrConfig Using Lucene MatchVersion: 6.5.0
[junit4] 2> 542775 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.IndexSchema [cdcr-source_shard1_replica1] Schema name=minimal
[junit4] 2> 542780 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.IndexSchema Loaded schema minimal/1.1 with uniqueid field id
[junit4] 2> 542784 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.CoreContainer Creating SolrCore 'cdcr-source_shard1_replica1' using configuration from collection cdcr-source
[junit4] 2> 542785 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [[cdcr-source_shard1_replica1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_A4EFB40B6DDF243-001\cdcr-source-001\node1\cdcr-source_shard1_replica1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\solr-core\test\J0\temp\solr.cloud.CdcrBootstrapTest_A4EFB40B6DDF243-001\cdcr-source-001\node1\.\cdcr-source_shard1_replica1\data\]
[junit4] 2> 542977 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.UpdateHandler Using UpdateLog implementation: org.apache.solr.update.UpdateLog
[junit4] 2> 542977 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.UpdateLog Initializing UpdateLog: dataDir= defaultSyncLevel=FLUSH numRecordsToKeep=100 maxNumLogsToKeep=10 numVersionBuckets=65536
[junit4] 2> 542979 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.CommitTracker Hard AutoCommit: disabled
[junit4] 2> 542979 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.CommitTracker Soft AutoCommit: disabled
[junit4] 2> 542982 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@26ab9653[cdcr-source_shard1_replica1] main]
[junit4] 2> 542984 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.r.ManagedResourceStorage Configured ZooKeeperStorageIO with znodeBase: /configs/cdcr-source
[junit4] 2> 542984 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.r.ManagedResourceStorage Loaded null at path _rest_managed.json using ZooKeeperStorageIO:path=/configs/cdcr-source
[junit4] 2> 542984 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.h.ReplicationHandler Commits will be reserved for 10000
[junit4] 2> 542985 INFO (searcherExecutor-1271-thread-1-processing-n:127.0.0.1:57900_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@26ab9653[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 542985 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.u.UpdateLog Could not find max version in index or recent updates, using new clock 1559420911199715328
[junit4] 2> 542993 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext Enough replicas found to continue.
[junit4] 2> 542993 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I may be the new leader - try and sync
[junit4] 2> 542993 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SyncStrategy Sync replicas to https://127.0.0.1:57900/solr/cdcr-source_shard1_replica1/
[junit4] 2> 542993 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SyncStrategy Sync Success - now sync replicas to me
[junit4] 2> 542993 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.SyncStrategy https://127.0.0.1:57900/solr/cdcr-source_shard1_replica1/ has no replicas
[junit4] 2> 543000 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ShardLeaderElectionContext I am the new leader: https://127.0.0.1:57900/solr/cdcr-source_shard1_replica1/ shard1
[junit4] 2> 543107 INFO (zkCallback-547-thread-1-processing-n:127.0.0.1:57900_solr) [n:127.0.0.1:57900_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 543153 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.c.ZkController I am the leader, no recovery necessary
[junit4] 2> 543160 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 x:cdcr-source_shard1_replica1] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/cores params={qt=/admin/cores&collection.configName=cdcr-source&newCollection=true&name=cdcr-source_shard1_replica1&action=CREATE&numShards=1&collection=cdcr-source&shard=shard1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2} status=0 QTime=1437
[junit4] 2> 543163 INFO (qtp789717658-3521) [n:127.0.0.1:57900_solr ] o.a.s.h.a.CollectionsHandler Wait for new collection to be active for at most 30 seconds. Check all shard replicas
[junit4] 2> 543259 INFO (zkCallback-547-thread-3-processing-n:127.0.0.1:57900_solr) [n:127.0.0.1:57900_solr ] o.a.s.c.c.ZkStateReader A cluster state change: [WatchedEvent state:SyncConnected type:NodeDataChanged path:/collections/cdcr-source/state.json] for collection [cdcr-source] has occurred - updating... (live nodes size: [1])
[junit4] 2> 543619 INFO (OverseerCollectionConfigSetProcessor-97463806830051331-127.0.0.1:57900_solr-n_0000000000) [n:127.0.0.1:57900_solr ] o.a.s.c.OverseerTaskQueue Response ZK path: /overseer/collection-queue-work/qnr-0000000000 doesn't exist. Requestor may have disconnected from ZooKeeper
[junit4] 2> 544163 INFO (qtp789717658-3521) [n:127.0.0.1:57900_solr ] o.a.s.s.HttpSolrCall [admin] webapp=null path=/admin/collections params={replicationFactor=1&collection.configName=cdcr-source&name=cdcr-source&action=CREATE&numShards=1&property.solr.directoryFactory=solr.StandardDirectoryFactory&wt=javabin&version=2} status=0 QTime=2555
[junit4] 1> Adding 10 docs with commit=true, numDocs=100
[junit4] 2> 544211 INFO (qtp789717658-3523) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_0 (1559420912444375040), source_1 (1559420912450666496), source_2 (1559420912450666497), source_3 (1559420912450666498), source_4 (1559420912450666499), source_5 (1559420912450666500), source_6 (1559420912450666501), source_7 (1559420912450666502), source_8 (1559420912450666503), source_9 (1559420912450666504), ... (100 adds)]} 0 39
[junit4] 2> 544238 INFO (qtp789717658-3525) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 544238 INFO (qtp789717658-3525) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27beba39
[junit4] 2> 544284 INFO (qtp789717658-3525) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5345dec6[cdcr-source_shard1_replica1] main]
[junit4] 2> 544284 INFO (searcherExecutor-1271-thread-1-processing-n:127.0.0.1:57900_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@5345dec6[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100)))}
[junit4] 2> 544284 INFO (qtp789717658-3525) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 544284 INFO (qtp789717658-3525) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 45
[junit4] 1> Adding 10 docs with commit=true, numDocs=200
[junit4] 2> 544296 INFO (qtp789717658-3518) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_100 (1559420912563912704), source_101 (1559420912568107008), source_102 (1559420912568107009), source_103 (1559420912568107010), source_104 (1559420912570204160), source_105 (1559420912571252736), source_106 (1559420912571252737), source_107 (1559420912571252738), source_108 (1559420912571252739), source_109 (1559420912571252740), ... (100 adds)]} 0 9
[junit4] 2> 544299 INFO (qtp789717658-3520) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 544299 INFO (qtp789717658-3520) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27beba39
[junit4] 2> 544346 INFO (qtp789717658-3520) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@3c313b30[cdcr-source_shard1_replica1] main]
[junit4] 2> 544346 INFO (searcherExecutor-1271-thread-1-processing-n:127.0.0.1:57900_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@3c313b30[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100)))}
[junit4] 2> 544346 INFO (qtp789717658-3520) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 544346 INFO (qtp789717658-3520) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 47
[junit4] 1> Adding 10 docs with commit=true, numDocs=300
[junit4] 2> 544355 INFO (qtp789717658-3522) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_200 (1559420912631021568), source_201 (1559420912634167296), source_202 (1559420912634167297), source_203 (1559420912634167298), source_204 (1559420912634167299), source_205 (1559420912634167300), source_206 (1559420912634167301), source_207 (1559420912634167302), source_208 (1559420912634167303), source_209 (1559420912634167304), ... (100 adds)]} 0 5
[junit4] 2> 544357 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 544357 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27beba39
[junit4] 2> 544407 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@b42b119[cdcr-source_shard1_replica1] main]
[junit4] 2> 544408 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 544408 INFO (searcherExecutor-1271-thread-1-processing-n:127.0.0.1:57900_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@b42b119[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100)))}
[junit4] 2> 544408 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 50
[junit4] 1> Adding 10 docs with commit=true, numDocs=400
[junit4] 2> 544416 INFO (qtp789717658-3521) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_300 (1559420912694984704), source_301 (1559420912698130432), source_302 (1559420912698130433), source_303 (1559420912698130434), source_304 (1559420912698130435), source_305 (1559420912698130436), source_306 (1559420912698130437), source_307 (1559420912698130438), source_308 (1559420912698130439), source_309 (1559420912698130440), ... (100 adds)]} 0 5
[junit4] 2> 544419 INFO (qtp789717658-3523) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 544419 INFO (qtp789717658-3523) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27beba39
[junit4] 2> 544470 INFO (qtp789717658-3523) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@5699accc[cdcr-source_shard1_replica1] main]
[junit4] 2> 544470 INFO (searcherExecutor-1271-thread-1-processing-n:127.0.0.1:57900_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@5699accc[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100)))}
[junit4] 2> 544471 INFO (qtp789717658-3523) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 544471 INFO (qtp789717658-3523) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 51
[junit4] 1> Adding 10 docs with commit=true, numDocs=500
[junit4] 2> 544481 INFO (qtp789717658-3525) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_400 (1559420912761044992), source_401 (1559420912763142144), source_402 (1559420912763142145), source_403 (1559420912763142146), source_404 (1559420912763142147), source_405 (1559420912763142148), source_406 (1559420912763142149), source_407 (1559420912763142150), source_408 (1559420912763142151), source_409 (1559420912763142152), ... (100 adds)]} 0 8
[junit4] 2> 544488 INFO (qtp789717658-3518) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 544488 INFO (qtp789717658-3518) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27beba39
[junit4] 2> 544562 INFO (qtp789717658-3518) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@2171cb19[cdcr-source_shard1_replica1] main]
[junit4] 2> 544562 INFO (qtp789717658-3518) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 544562 INFO (searcherExecutor-1271-thread-1-processing-n:127.0.0.1:57900_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@2171cb19[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100) Uninverting(_4(6.5.0):C100)))}
[junit4] 2> 544564 INFO (qtp789717658-3518) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 75
[junit4] 1> Adding 10 docs with commit=true, numDocs=600
[junit4] 2> 544579 INFO (qtp789717658-3520) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_500 (1559420912857513984), source_501 (1559420912858562560), source_502 (1559420912858562561), source_503 (1559420912860659712), source_504 (1559420912860659713), source_505 (1559420912860659714), source_506 (1559420912860659715), source_507 (1559420912860659716), source_508 (1559420912860659717), source_509 (1559420912860659718), ... (100 adds)]} 0 12
[junit4] 2> 544580 INFO (qtp789717658-3520) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 544580 INFO (qtp789717658-3520) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27beba39
[junit4] 2> 544636 INFO (qtp789717658-3520) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@24844131[cdcr-source_shard1_replica1] main]
[junit4] 2> 544637 INFO (qtp789717658-3520) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 544637 INFO (searcherExecutor-1271-thread-1-processing-n:127.0.0.1:57900_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@24844131[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100) Uninverting(_4(6.5.0):C100) Uninverting(_5(6.5.0):C100)))}
[junit4] 2> 544637 INFO (qtp789717658-3520) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 57
[junit4] 1> Adding 10 docs with commit=true, numDocs=700
[junit4] 2> 544646 INFO (qtp789717658-3524) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_600 (1559420912935108608), source_601 (1559420912937205760), source_602 (1559420912937205761), source_603 (1559420912937205762), source_604 (1559420912937205763), source_605 (1559420912937205764), source_606 (1559420912937205765), source_607 (1559420912937205766), source_608 (1559420912937205767), source_609 (1559420912937205768), ... (100 adds)]} 0 5
[junit4] 2> 544647 INFO (qtp789717658-3521) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 544647 INFO (qtp789717658-3521) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27beba39
[junit4] 2> 544712 INFO (qtp789717658-3521) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@52c45a85[cdcr-source_shard1_replica1] main]
[junit4] 2> 544714 INFO (qtp789717658-3521) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 544724 INFO (searcherExecutor-1271-thread-1-processing-n:127.0.0.1:57900_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@52c45a85[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100) Uninverting(_4(6.5.0):C100) Uninverting(_5(6.5.0):C100) Uninverting(_6(6.5.0):C100)))}
[junit4] 2> 544724 INFO (qtp789717658-3521) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 77
[junit4] 1> Adding 10 docs with commit=true, numDocs=800
[junit4] 2> 544742 INFO (qtp789717658-3523) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_700 (1559420913026334720), source_701 (1559420913041014784), source_702 (1559420913041014785), source_703 (1559420913041014786), source_704 (1559420913041014787), source_705 (1559420913041014788), source_706 (1559420913041014789), source_707 (1559420913041014790), source_708 (1559420913041014791), source_709 (1559420913041014792), ... (100 adds)]} 0 16
[junit4] 2> 544746 INFO (qtp789717658-3523) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 544746 INFO (qtp789717658-3523) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27beba39
[junit4] 2> 544832 INFO (qtp789717658-3523) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@da634c6[cdcr-source_shard1_replica1] main]
[junit4] 2> 544833 INFO (qtp789717658-3523) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 544833 INFO (searcherExecutor-1271-thread-1-processing-n:127.0.0.1:57900_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@da634c6[cdcr-source_shard1_replica1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C100) Uninverting(_1(6.5.0):C100) Uninverting(_2(6.5.0):C100) Uninverting(_3(6.5.0):C100) Uninverting(_4(6.5.0):C100) Uninverting(_5(6.5.0):C100) Uninverting(_6(6.5.0):C100) Uninverting(_7(6.5.0):C100)))}
[junit4] 2> 544834 INFO (qtp789717658-3523) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&waitSearcher=true&commit=true&softCommit=false&wt=javabin&version=2}{commit=} 0 88
[junit4] 1> Adding 10 docs with commit=true, numDocs=900
[junit4] 2> 544846 INFO (qtp789717658-3518) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.p.LogUpdateProcessorFactory [cdcr-source_shard1_replica1] webapp=/solr path=/update params={_stateVer_=cdcr-source:3&wt=javabin&version=2}{add=[source_800 (1559420913143775232), source_801 (1559420913146920960), source_802 (1559420913146920961), source_803 (1559420913146920962), source_804 (1559420913146920963), source_805 (1559420913146920964), source_806 (1559420913146920965), source_807 (1559420913146920966), source_808 (1559420913146920967), source_809 (1559420913146920968), ... (100 adds)]} 0 6
[junit4] 2> 544848 INFO (qtp789717658-3522) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 544848 INFO (qtp789717658-3522) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.SolrIndexWriter Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@27beba39
[junit4] 2> 544915 INFO (qtp789717658-3522) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.s.SolrIndexSearcher Opening [Searcher@150534c2[cdcr-source_shard1_replica1] main]
[junit4] 2> 544916 INFO (qtp789717658-3522) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.u.DirectUpdateHandler2 end_commit_flush
[junit4] 2> 544916 INFO (searcherExecutor-1271-thread-1-processing-n:127.0.0.1:57900_solr x:cdcr-source_shard1_replica1 s:shard1 c:cdcr-source r:core_node1) [n:127.0.0.1:57900_solr c:cdcr-source s:shard1 r:core_node1 x:cdcr-source_shard1_replica1] o.a.s.c.SolrCore [cdcr-source_shard1_replica1] Registered new searcher Searcher@150534c2[cdcr-source_shard1_replica1] main{Exitab
[...truncated too long message...]
745)
[junit4] 2> 31623 T33 oas.SolrTestCaseJ4.setUp ###Starting testSimple
[junit4] 2> 31661 T33 oejs.Server.doStart jetty-9.3.14.v20161028
[junit4] 2> 31664 T33 oejsh.ContextHandler.doStart Started o.e.j.s.ServletContextHandler@3b10beec{/solr,null,AVAILABLE}
[junit4] 2> 31666 T33 oejs.AbstractConnector.doStart Started ServerConnector@719e9383{HTTP/1.1,[http/1.1]}{127.0.0.1:64137}
[junit4] 2> 31667 T33 oejs.Server.doStart Started @35487ms
[junit4] 2> 31667 T33 oascse.JettySolrRunner$1.lifeCycleStarted Jetty properties: {solr.data.dir=C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\contrib\solr-dataimporthandler\test\J1\temp\solr.handler.dataimport.TestContentStreamDataSource_1B165D26DAB485F1-001\inst-002\collection1\data, hostContext=/solr, hostPort=64137}
[junit4] 2> 31668 T33 oass.StartupLoggingUtils.checkLogDir ERROR Missing Java Option solr.log.dir. Logging may be missing or incomplete.
[junit4] 2> 31668 T33 oass.SolrDispatchFilter.logWelcomeBanner ___ _ Welcome to Apache Solr™ version 6.5.0
[junit4] 2> 31668 T33 oass.SolrDispatchFilter.logWelcomeBanner / __| ___| |_ _ Starting in standalone mode on port null
[junit4] 2> 31669 T33 oass.SolrDispatchFilter.logWelcomeBanner \__ \/ _ \ | '_| Install dir: null
[junit4] 2> 31669 T33 oass.SolrDispatchFilter.logWelcomeBanner |___/\___/_|_| Start time: 2017-02-15T17:48:27.620Z
[junit4] 2> 31671 T33 oasc.SolrXmlConfig.fromFile Loading container configuration from C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\contrib\solr-dataimporthandler\test\J1\temp\solr.handler.dataimport.TestContentStreamDataSource_1B165D26DAB485F1-001\inst-002\solr.xml
[junit4] 2> 31710 T33 oasu.UpdateShardHandler.<init> Creating UpdateShardHandler HTTP client with params: socketTimeout=600000&connTimeout=60000&retry=true
[junit4] 2> 31928 T33 oasc.CorePropertiesLocator.discover Found 1 core definitions underneath C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\contrib\solr-dataimporthandler\test\J1\temp\solr.handler.dataimport.TestContentStreamDataSource_1B165D26DAB485F1-001\inst-002
[junit4] 2> 31929 T33 oasc.CorePropertiesLocator.discover Cores are: [collection1]
[junit4] 2> 32070 T68 x:x:collection1 oasc.SolrConfig.<init> Using Lucene MatchVersion: 6.5.0
[junit4] 2> 32118 T68 x:x:collection1 oass.IndexSchema.readSchema [collection1] Schema name=dih_test
[junit4] 2> 32139 T68 x:x:collection1 oass.IndexSchema.readSchema WARN [collection1] default search field in schema is desc. WARNING: Deprecated, please use 'df' on request instead.
[junit4] 2> 32140 T68 x:x:collection1 oass.IndexSchema.readSchema WARN [collection1] query parser default operator is OR. WARNING: Deprecated, please use 'q.op' on request instead.
[junit4] 2> 32141 T68 x:x:collection1 oass.IndexSchema.readSchema Loaded schema dih_test/4.0 with uniqueid field id
[junit4] 2> 32151 T68 x:x:collection1 oasc.CoreContainer.create Creating SolrCore 'collection1' using configuration from instancedir C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\contrib\solr-dataimporthandler\test\J1\temp\solr.handler.dataimport.TestContentStreamDataSource_1B165D26DAB485F1-001\inst-002\collection1
[junit4] 2> 32152 T68 x:x:collection1 oasc.SolrCore.<init> [[collection1] ] Opening new SolrCore at [C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\contrib\solr-dataimporthandler\test\J1\temp\solr.handler.dataimport.TestContentStreamDataSource_1B165D26DAB485F1-001\inst-002\collection1], dataDir=[C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\contrib\solr-dataimporthandler\test\J1\temp\solr.handler.dataimport.TestContentStreamDataSource_1B165D26DAB485F1-001\inst-002\collection1\data\]
[junit4] 2> 32373 T68 x:x:collection1 oasu.CommitTracker.<init> Hard AutoCommit: disabled
[junit4] 2> 32374 T68 x:x:collection1 oasu.CommitTracker.<init> Soft AutoCommit: disabled
[junit4] 2> 32375 T68 x:x:collection1 oass.SolrIndexSearcher.<init> Opening [Searcher@2506448e[collection1] main]
[junit4] 2> 32376 T68 x:x:collection1 oasr.ManagedResourceStorage$FileStorageIO.configure File-based storage initialized to use dir: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\contrib\solr-dataimporthandler\test\J1\temp\solr.handler.dataimport.TestContentStreamDataSource_1B165D26DAB485F1-001\inst-002\collection1\conf
[junit4] 2> 32377 T68 x:x:collection1 oash.ReplicationHandler.inform Commits will be reserved for 10000
[junit4] 2> 32378 T72 x:x:collection1 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2506448e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> 32378 T72 x:x:collection1 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 32379 T72 x:x:collection1 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2506448e[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader())}
[junit4] 2> ASYNC NEW_CORE C6 name=collection1 org.apache.solr.core.SolrCore@5e491590
[junit4] 2> 32488 T57 x:x:collection1 C6 oashd.DataImporter.maybeReloadConfiguration Loading DIH Configuration: data-config.xml
[junit4] 2> 32497 T57 x:x:collection1 C6 oashd.DataImporter.loadDataConfig Data Configuration loaded successfully
[junit4] 2> 32497 T57 x:x:collection1 C6 oashd.DataImporter.doFullImport Starting Full Import
[junit4] 2> 32498 T57 x:x:collection1 C6 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: dataimport.properties
[junit4] 2> 32505 T57 x:x:collection1 C6 oashd.DocBuilder.finish Import completed successfully
[junit4] 2> 32506 T57 x:x:collection1 C6 oasu.DirectUpdateHandler2.commit start commit{,optimize=false,openSearcher=true,waitSearcher=true,expungeDeletes=false,softCommit=false,prepareCommit=false}
[junit4] 2> 32506 T57 x:x:collection1 C6 oasu.SolrIndexWriter.setCommitData Calling setCommitData with IW:org.apache.solr.update.SolrIndexWriter@2bb7999b
[junit4] 2> 32525 T57 x:x:collection1 C6 oass.SolrIndexSearcher.<init> Opening [Searcher@2b8a7493[collection1] main]
[junit4] 2> 32526 T57 x:x:collection1 C6 oasu.DirectUpdateHandler2.commit end_commit_flush
[junit4] 2> 32527 T72 x:x:collection1 C6 oasc.QuerySenderListener.newSearcher QuerySenderListener sending requests to Searcher@2b8a7493[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C2)))}
[junit4] 2> 32529 T72 x:x:collection1 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=solr&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 32529 T72 x:x:collection1 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=rocks&distrib=false&start=0&rows=10&event=newSearcher} hits=0 status=0 QTime=0
[junit4] 2> 32531 T72 x:x:collection1 C6 oasc.SolrCore.execute [collection1] webapp=null path=null params={q=static+newSearcher+warming+query+from+solrconfig.xml&distrib=false&event=newSearcher} hits=0 status=0 QTime=1
[junit4] 2> 32531 T72 x:x:collection1 C6 oasc.QuerySenderListener.newSearcher QuerySenderListener done.
[junit4] 2> 32531 T72 x:x:collection1 C6 oasc.SolrCore.registerSearcher [collection1] Registered new searcher Searcher@2b8a7493[collection1] main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(6.5.0):C2)))}
[junit4] 2> 32531 T57 x:x:collection1 C6 oashd.SimplePropertiesWriter.readIndexerProperties WARN Unable to read: dataimport.properties
[junit4] 2> 32538 T57 x:x:collection1 C6 oashd.SimplePropertiesWriter.persist Wrote last indexed time to dataimport.properties
[junit4] 2> 32539 T57 x:x:collection1 C6 oashd.DocBuilder.execute Time taken = 0:0:0.39
[junit4] 2> 32539 T57 x:x:collection1 C6 oasup.LogUpdateProcessorFactory$LogUpdateProcessor.finish [collection1] webapp=/solr path=/dataimport params={clean=false&wt=javabin&version=2&command=full-import}{add=[1, 2],commit=} 0 52
[junit4] 2> 32549 T58 x:x:collection1 C6 oasc.SolrCore.execute [collection1] webapp=/solr path=/select params={q=*:*&wt=javabin&version=2} hits=2 status=0 QTime=1
[junit4] 2> 32554 T33 oejs.AbstractConnector.doStop Stopped ServerConnector@719e9383{HTTP/1.1,[http/1.1]}{127.0.0.1:0}
[junit4] 2> 32555 T33 oasc.CoreContainer.shutdown Shutting down CoreContainer instance=1328323990
[junit4] 2> 32561 T75 x:x:collection1 oasc.SolrCore.close [collection1] CLOSING SolrCore org.apache.solr.core.SolrCore@5e491590
[junit4] 2> 32564 T75 x:x:collection1 oasm.SolrMetricManager.closeReporters Closing metric reporters for: solr.core.collection1
[junit4] 2> 32566 T33 oasm.SolrMetricManager.closeReporters Closing metric reporters for: solr.node
[junit4] 2> 32572 T33 oejsh.ContextHandler.doStop Stopped o.e.j.s.ServletContextHandler@3b10beec{/solr,null,UNAVAILABLE}
[junit4] 2> 32575 T33 oas.SolrTestCaseJ4.tearDown ###Ending testSimple
[junit4] 2> 32577 T33 oas.SolrTestCaseJ4.deleteCore ###deleteCore
[junit4] 2> NOTE: leaving temporary files on disk at: C:\Users\jenkins\workspace\Lucene-Solr-6.x-Windows\solr\build\contrib\solr-dataimporthandler\test\J1\temp\solr.handler.dataimport.TestContentStreamDataSource_1B165D26DAB485F1-001
[junit4] 2> NOTE: test params are: codec=Lucene62, sim=RandomSimilarity(queryNorm=true,coord=no): {}, locale=ms-MY, timezone=US/Mountain
[junit4] 2> NOTE: Windows 10 10.0 amd64/Oracle Corporation 1.8.0_121 (64-bit)/cpus=3,threads=1,free=40770560,total=67108864
[junit4] 2> NOTE: All tests run in this JVM: [TestEphemeralCache, TestDocBuilder2, TestContentStreamDataSource]
[junit4] Completed [5/38 (1!)] on J1 in 8.06s, 2 tests, 1 failure <<< FAILURES!
[...truncated 58033 lines...]