[
https://issues.apache.org/jira/browse/SOLR-9144?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Hoss Man updated SOLR-9144:
---------------------------
Attachment: Lucene-Solr-Tests-master_1157_log.txt
Attaching the logs from jenkins build sarowe mentioned, i haven't dug into it
much but from skimming it looks like there is a problem reloading the core due
to a NoSuchFileException and then the test just times out waiting for core to
come up -- instead of explicitly looking for CoreInitFailure info from the core
admin API.
Why the NoSuchFileException happens is something i can't really explain
though...
{noformat}
[junit4] 2> 550370 ERROR (Thread-2828) [ x:collection1]
o.a.s.h.IndexFetcher Could not reload core
[junit4] 2> org.apache.solr.common.SolrException: Unable to reload core
[collection1]
[junit4] 2> at
org.apache.solr.core.CoreContainer.reload(CoreContainer.java:944)
[junit4] 2> at
org.apache.solr.handler.IndexFetcher$1.run(IndexFetcher.java:775)
[junit4] 2> Caused by: org.apache.solr.common.SolrException: Error opening
new searcher
[junit4] 2> at
org.apache.solr.core.SolrCore.<init>(SolrCore.java:773)
[junit4] 2> at
org.apache.solr.core.SolrCore.reload(SolrCore.java:462)
[junit4] 2> at
org.apache.solr.core.CoreContainer.reload(CoreContainer.java:938)
[junit4] 2> ... 1 more
[junit4] 2> Caused by: org.apache.solr.common.SolrException: Error opening
new searcher
[junit4] 2> at
org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1642)
[junit4] 2> at
org.apache.solr.core.SolrCore.getSearcher(SolrCore.java:1753)
[junit4] 2> at
org.apache.solr.core.SolrCore.initSearcher(SolrCore.java:860)
[junit4] 2> at
org.apache.solr.core.SolrCore.<init>(SolrCore.java:746)
[junit4] 2> ... 3 more
[junit4] 2> Caused by: java.nio.file.NoSuchFileException:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/
J0/temp/solr.handler.TestReplicationHandler_202BDCCB6CD49CB3-001/solr-instance-030/collection1/data/index.20160520144210238/_0.fnm
[junit4] 2> at
sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
[junit4] 2> at
sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
[junit4] 2> at
sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
[junit4] 2> at
sun.nio.fs.UnixFileSystemProvider.newFileChannel(UnixFileSystemProvider.java:177)
[junit4] 2> at
java.nio.channels.FileChannel.open(FileChannel.java:287)
[junit4] 2> at
java.nio.channels.FileChannel.open(FileChannel.java:335)
[junit4] 2> at
org.apache.lucene.store.MMapDirectory.openInput(MMapDirectory.java:238)
[junit4] 2> at
org.apache.lucene.store.NRTCachingDirectory.openInput(NRTCachingDirectory.java:192)
[junit4] 2> at
org.apache.lucene.store.Directory.openChecksumInput(Directory.java:113)
[junit4] 2> at
org.apache.lucene.codecs.lucene60.Lucene60FieldInfosFormat.read(Lucene60FieldInfosFormat.java:113)
[junit4] 2> at
org.apache.lucene.index.SegmentCoreReaders.<init>(SegmentCoreReaders.java:101)
[junit4] 2> at
org.apache.lucene.index.SegmentReader.<init>(SegmentReader.java:67)
[junit4] 2> at
org.apache.lucene.index.ReadersAndUpdates.getReader(ReadersAndUpdates.java:145)
[junit4] 2> at
org.apache.lucene.index.ReadersAndUpdates.getReadOnlyClone(ReadersAndUpdates.java:197)
[junit4] 2> at
org.apache.lucene.index.StandardDirectoryReader.open(StandardDirectoryReader.java:102)
[junit4] 2> at
org.apache.lucene.index.IndexWriter.getReader(IndexWriter.java:444)
[junit4] 2> at
org.apache.lucene.index.DirectoryReader.open(DirectoryReader.java:103)
[junit4] 2> at
org.apache.lucene.index.DirectoryReader.open(DirectoryReader.java:79)
[junit4] 2> at
org.apache.solr.core.StandardIndexReaderFactory.newReader(StandardIndexReaderFactory.java:39)
[junit4] 2> at
org.apache.solr.core.SolrCore.openNewSearcher(SolrCore.java:1606)
[junit4] 2> ... 6 more
[junit4] 2> 550371 INFO (explicit-fetchindex-cmd) [ x:collection1]
o.a.s.h.IndexFetcher removing old index directory NRTCachingDirectory(MMap
Directory@/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_202BDCCB6
CD49CB3-001/solr-instance-030/collection1/data/index.20160520144210238
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@6a55f8ea; maxCach
eMB=48.0 maxMergeSizeMB=4.0)
[junit4] 2> 550372 INFO (explicit-fetchindex-cmd) [ x:collection1]
o.a.s.u.DefaultSolrCoreState Rollback old IndexWriter... core=collection1
[junit4] 2> 550372 ERROR (explicit-fetchindex-cmd) [ x:collection1]
o.a.s.u.SolrIndexWriter Exception rolling back IndexWriter
[junit4] 2> java.nio.file.NoSuchFileException:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_202BDCCB6CD49CB3-001/solr-instance-030/collection1/data/index.20160520144210238
[junit4] 2> at
sun.nio.fs.UnixException.translateToIOException(UnixException.java:86)
[junit4] 2> at
sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:102)
[junit4] 2> at
sun.nio.fs.UnixException.rethrowAsIOException(UnixException.java:107)
[junit4] 2> at
sun.nio.fs.UnixFileSystemProvider.newDirectoryStream(UnixFileSystemProvider.java:427)
[junit4] 2> at
java.nio.file.Files.newDirectoryStream(Files.java:457)
[junit4] 2> at
org.apache.lucene.store.FSDirectory.listAll(FSDirectory.java:215)
[junit4] 2> at
org.apache.lucene.store.FSDirectory.listAll(FSDirectory.java:234)
[junit4] 2> at
org.apache.lucene.store.NRTCachingDirectory.listAll(NRTCachingDirectory.java:103)
[junit4] 2> at
org.apache.lucene.store.FilterDirectory.listAll(FilterDirectory.java:57)
[junit4] 2> at
org.apache.lucene.index.IndexFileDeleter.refresh(IndexFileDeleter.java:428)
[junit4] 2> at
org.apache.lucene.index.IndexWriter.rollbackInternalNoCommit(IndexWriter.java:2130)
[junit4] 2> at
org.apache.lucene.index.IndexWriter.rollbackInternal(IndexWriter.java:2072)
[junit4] 2> at
org.apache.lucene.index.IndexWriter.rollback(IndexWriter.java:2065)
[junit4] 2> at
org.apache.solr.update.SolrIndexWriter.rollback(SolrIndexWriter.java:145)
[junit4] 2> at
org.apache.solr.update.DefaultSolrCoreState.changeWriter(DefaultSolrCoreState.java:195)
[junit4] 2> at
org.apache.solr.update.DefaultSolrCoreState.newIndexWriter(DefaultSolrCoreState.java:212)
[junit4] 2> at
org.apache.solr.update.DirectUpdateHandler2.newIndexWriter(DirectUpdateHandler2.java:698)
[junit4] 2> at
org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:522)
[junit4] 2> at
org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:535)
[junit4] 2> at
org.apache.solr.handler.IndexFetcher.fetchLatestIndex(IndexFetcher.java:265)
[junit4] 2> at
org.apache.solr.handler.ReplicationHandler.doFetch(ReplicationHandler.java:388)
[junit4] 2> at
org.apache.solr.handler.ReplicationHandler$1.run(ReplicationHandler.java:276)
[junit4] 2> 550373 INFO (explicit-fetchindex-cmd) [ x:collection1]
o.a.s.u.RandomMergePolicy RandomMergePolicy wrapping class
org.apache.lucene.index.LogByteSizeMergePolicy: [LogByteSizeMergePolicy:
minMergeSize=1677721, mergeFactor=31, maxMergeSize=2147483648,
maxMergeSizeForForcedMerge=9223372036854775807, calibrateSizeByDeletes=true,
maxMergeDocs=2147483647, maxCFSSegmentSizeMB=8.796093022207999E12,
noCFSRatio=0.0]
[junit4] 2> 550375 INFO (explicit-fetchindex-cmd) [ x:collection1]
o.a.s.c.SolrDeletionPolicy SolrDeletionPolicy.onInit: commits: num=1
[junit4] 2>
commit{dir=NRTCachingDirectory(MMapDirectory@/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_202BDCCB6CD49CB3-001/solr-instance-030/collection1/data/index.20160520144210451
lockFactory=org.apache.lucene.store.SingleInstanceLockFactory@48543e8b;
maxCacheMB=48.0 maxMergeSizeMB=4.0),segFN=segments_5,generation=5}
[junit4] 2> 550375 INFO (explicit-fetchindex-cmd) [ x:collection1]
o.a.s.c.SolrDeletionPolicy newest commit generation = 5
[junit4] 2> 550376 INFO (explicit-fetchindex-cmd) [ x:collection1]
o.a.s.u.DefaultSolrCoreState New IndexWriter is ready to be used.
[junit4] 2> 550379 INFO (explicit-fetchindex-cmd) [ x:collection1]
o.a.s.s.SolrIndexSearcher Opening [Searcher@1727cf9e[collection1] main]
[junit4] 2> 550379 INFO
(searcherExecutor-3730-thread-1-processing-x:collection1) [ x:collection1]
o.a.s.c.SolrCore [collection1] Registered new searcher
Searcher@1727cf9e[collection1]
main{ExitableDirectoryReader(UninvertingDirectoryReader(Uninverting(_0(7.0.0):C159)
Uninverting(_1(7.0.0):C105) Uninverting(_2(7.0.0):C161)
Uninverting(_3(7.0.0):C45)))}
[junit4] 2> 550379 INFO (qtp1591120775-7063) [ x:collection1]
o.a.s.c.S.Request [collection1] webapp=/solr path=/replication
params={wait=true&masterUrl=http://127.0.0.1:33519/solr/collection1/replication&command=fetchindex}
status=0 QTime=173
[junit4] 2> 550380 INFO (qtp1591120775-7063) [ x:collection1]
o.a.s.c.CachingDirectoryFactory looking to close
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_202BDCCB6CD49CB3-001/solr-instance-030/collection1/data/index.20160520144210238
[CachedDir<<refCount=0;path=/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_202BDCCB6CD49CB3-001/solr-instance-030/collection1/data/index.20160520144210238;done=true>>]
[junit4] 2> 550380 INFO (qtp1591120775-7063) [ x:collection1]
o.a.s.c.CachingDirectoryFactory Closing directory,
CoreContainer#isShutdown=false
[junit4] 2> 550380 INFO (qtp1591120775-7063) [ x:collection1]
o.a.s.c.CachingDirectoryFactory Closing directory:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_202BDCCB6CD49CB3-001/solr-instance-030/collection1/data/index.20160520144210238
[junit4] 2> 550380 INFO (qtp1591120775-7063) [ x:collection1]
o.a.s.c.CachingDirectoryFactory Removing directory before core close:
/x1/jenkins/jenkins-slave/workspace/Lucene-Solr-Tests-master/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_202BDCCB6CD49CB3-001/solr-instance-030/collection1/data/index.20160520144210238
[junit4] 2> 550383 INFO (qtp1591120775-7070) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={core=collection1&action=status&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 550585 INFO (qtp1591120775-7068) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={core=collection1&action=status&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 550786 INFO (qtp1591120775-7066) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={core=collection1&action=status&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 550988 INFO (qtp1591120775-7064) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={core=collection1&action=status&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 551190 INFO (qtp1591120775-7067) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={core=collection1&action=status&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 551392 INFO (qtp1591120775-7063) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={core=collection1&action=status&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 551594 INFO (qtp1591120775-7070) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={core=collection1&action=status&wt=javabin&version=2} status=0 QTime=0
[junit4] 2> 551795 INFO (qtp1591120775-7068) [ ] o.a.s.s.HttpSolrCall
[admin] webapp=null path=/admin/cores
params={core=collection1&action=status&wt=javabin&version=2} status=0 QTime=0
...
{noformat}
> TestReplicationHandler.doTestStressReplication(): timed out waiting for
> collection1 startAt time to exceed: [point-in-time]
> ---------------------------------------------------------------------------------------------------------------------------
>
> Key: SOLR-9144
> URL: https://issues.apache.org/jira/browse/SOLR-9144
> Project: Solr
> Issue Type: Bug
> Components: replication (java)
> Affects Versions: 6.0, 6.1, master (7.0)
> Reporter: Steve Rowe
> Attachments: Lucene-Solr-Tests-master_1157_log.txt, tests-failures.txt
>
>
> I found this while doing other testing - reproduces for me only on the
> branch_6_0 branch, including at tag {{releases/lucene-solr/6.0.0}}:
> {noformat}
> 2> NOTE: reproduce with: ant test -Dtestcase=TestReplicationHandler
> -Dtests.method=doTestStressReplication -Dtests.seed=251666D68D49C05B
> -Dtests.slow=true
> -Dtests.linedocsfile=/home/jenkins/lucene-data/enwiki.random.lines.txt
> -Dtests.locale=sr-Latn-ME -Dtests.timezone=Pacific/Niue -Dtests.asserts=true
> -Dtests.file.encoding=US-ASCII
> [14:10:25.387] FAILURE 34.1s | TestReplicationHandler.doTestStressReplication
> <<<
> > Throwable #1: java.lang.AssertionError: timed out waiting for
> collection1 startAt time to exceed: Sat May 21 07:10:28 NUT 2016
> > at
> __randomizedtesting.SeedInfo.seed([251666D68D49C05B:FEBD66108861A9E8]:0)
> > at org.junit.Assert.fail(Assert.java:93)
> > at
> org.apache.solr.handler.TestReplicationHandler.watchCoreStartAt(TestReplicationHandler.java:1499)
> > at
> org.apache.solr.handler.TestReplicationHandler.doTestStressReplication(TestReplicationHandler.java:851)
> > 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:1764)
> > at
> com.carrotsearch.randomizedtesting.RandomizedRunner$8.evaluate(RandomizedRunner.java:871)
> > at
> com.carrotsearch.randomizedtesting.RandomizedRunner$9.evaluate(RandomizedRunner.java:907)
> > at
> com.carrotsearch.randomizedtesting.RandomizedRunner$10.evaluate(RandomizedRunner.java:921)
> > at
> com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
> > at
> org.apache.lucene.util.TestRuleSetupTeardownChained$1.evaluate(TestRuleSetupTeardownChained.java:49)
> > at
> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
> > at
> org.apache.lucene.util.TestRuleThreadAndTestName$1.evaluate(TestRuleThreadAndTestName.java:48)
> > at
> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
> > at
> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
> > at
> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> > at
> com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
> > at
> com.carrotsearch.randomizedtesting.ThreadLeakControl.forkTimeoutingTask(ThreadLeakControl.java:809)
> > at
> com.carrotsearch.randomizedtesting.ThreadLeakControl$3.evaluate(ThreadLeakControl.java:460)
> > at
> com.carrotsearch.randomizedtesting.RandomizedRunner.runSingleTest(RandomizedRunner.java:880)
> > at
> com.carrotsearch.randomizedtesting.RandomizedRunner$5.evaluate(RandomizedRunner.java:781)
> > at
> com.carrotsearch.randomizedtesting.RandomizedRunner$6.evaluate(RandomizedRunner.java:816)
> > at
> com.carrotsearch.randomizedtesting.RandomizedRunner$7.evaluate(RandomizedRunner.java:827)
> > at
> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> > at
> com.carrotsearch.randomizedtesting.rules.SystemPropertiesRestoreRule$1.evaluate(SystemPropertiesRestoreRule.java:57)
> > at
> org.apache.lucene.util.AbstractBeforeAfterRule$1.evaluate(AbstractBeforeAfterRule.java:45)
> > at
> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> > at
> org.apache.lucene.util.TestRuleStoreClassName$1.evaluate(TestRuleStoreClassName.java:41)
> > at
> com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
> > at
> com.carrotsearch.randomizedtesting.rules.NoShadowingOrOverridesOnMethodsRule$1.evaluate(NoShadowingOrOverridesOnMethodsRule.java:40)
> > at
> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> > at
> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> > at
> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> > at
> org.apache.lucene.util.TestRuleAssertionsRequired$1.evaluate(TestRuleAssertionsRequired.java:53)
> > at
> org.apache.lucene.util.TestRuleMarkFailure$1.evaluate(TestRuleMarkFailure.java:47)
> > at
> org.apache.lucene.util.TestRuleIgnoreAfterMaxFailures$1.evaluate(TestRuleIgnoreAfterMaxFailures.java:64)
> > at
> org.apache.lucene.util.TestRuleIgnoreTestSuites$1.evaluate(TestRuleIgnoreTestSuites.java:54)
> > at
> com.carrotsearch.randomizedtesting.rules.StatementAdapter.evaluate(StatementAdapter.java:36)
> > at
> com.carrotsearch.randomizedtesting.ThreadLeakControl$StatementRunner.run(ThreadLeakControl.java:367)
> > at java.lang.Thread.run(Thread.java:745)
> {noformat}
> I don't know if it's relevant, but there are several CorruptIndexExceptions
> logged as warnings, e.g.:
> {noformat}
> 2> 6505 WARN (qtp998957110-74) [ x:collection1]
> o.a.s.h.ReplicationHandler Could not read checksum from index file:
> _0_MockRandom_0.sd
> 2> org.apache.lucene.index.CorruptIndexException: misplaced codec footer
> (file truncated?): length=8 but footerLength==16
> (resource=MMapIndexInput(path="/Users/sarowe/git/lucene-solr/solr/build/solr-core/test/J0/temp/solr.handler.TestReplicationHandler_251666D68D49C05B-002/solr-instance-001/collection1/data/index/_0_MockRandom_0.sd"))
> 2> at
> org.apache.lucene.codecs.CodecUtil.retrieveChecksum(CodecUtil.java:430)
> 2> at
> org.apache.solr.handler.ReplicationHandler.getFileList(ReplicationHandler.java:564)
> 2> at
> org.apache.solr.handler.ReplicationHandler.handleRequestBody(ReplicationHandler.java:252)
> {noformat}
> I'll attach the {{tests-failures.txt}} from a run with this seed.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
