[infinispan-issues] [JBoss JIRA] (ISPN-8160) ClusteredCacheWithAffinityIndexManagerTxTest random failures with trace logging enabled

[Dan Berindei (JIRA)]

    [ https://issues.jboss.org/browse/ISPN-8160?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=13566534#comment-13566534 ] 

Dan Berindei commented on ISPN-8160:
------------------------------------

I got some new failures locally and I didn't see any exception other than the timeout exception during the failing test.

I also tried changing the number of segments in the cache, and it definitely has an impact on the size of the log and the duration of the test:  with the default 256 segments, a single test method ({{testConditionalRemoveFromBackup}}) takes 12s and logs 70mb; with 32 segments, the same method takes 3.6s and logs 13.7mb. Maybe we should change the cache configuration in the tests and/or warn the user when they configure the AffinityIndexManager with such a big number of segments?

> ClusteredCacheWithAffinityIndexManagerTxTest random failures with trace logging enabled
> ---------------------------------------------------------------------------------------
>
>                 Key: ISPN-8160
>                 URL: https://issues.jboss.org/browse/ISPN-8160
>             Project: Infinispan
>          Issue Type: Bug
>          Components: Test Suite - Query
>    Affects Versions: 9.1.0.Final
>            Reporter: Dan Berindei
>            Assignee: Gustavo Fernandes
>            Priority: Critical
>              Labels: testsuite_stability
>
> The test usually passes when run by itself, but when run in parallel with other tests often getting one or more failures. The failing test method is not always the same, e.g.
> {noformat}
> 13:10:28,264 ERROR (testng-Test:[]) [TestSuiteProgress] Test failed: org.infinispan.query.blackbox.ClusteredCacheWithAffinityIndexManagerTxTest.testCompute
> org.hibernate.search.exception.SearchException: Unable to reopen IndexReader
> 	at org.hibernate.search.indexes.impl.SharingBufferReaderProvider$PerDirectoryLatestReader.refreshAndGet(SharingBufferReaderProvider.java:242) ~[hibernate-search-engine-5.8.0.Beta4.jar:5.8.0.Beta4]
> 	at org.hibernate.search.indexes.impl.SharingBufferReaderProvider.openIndexReader(SharingBufferReaderProvider.java:73) ~[hibernate-search-engine-5.8.0.Beta4.jar:5.8.0.Beta4]
> 	at org.hibernate.search.indexes.impl.SharingBufferReaderProvider.openIndexReader(SharingBufferReaderProvider.java:35) ~[hibernate-search-engine-5.8.0.Beta4.jar:5.8.0.Beta4]
> 	at org.hibernate.search.reader.impl.ManagedMultiReader.createInstance(ManagedMultiReader.java:69) ~[hibernate-search-engine-5.8.0.Beta4.jar:5.8.0.Beta4]
> 	at org.hibernate.search.reader.impl.MultiReaderFactory.openReader(MultiReaderFactory.java:48) ~[hibernate-search-engine-5.8.0.Beta4.jar:5.8.0.Beta4]
> 	at org.hibernate.search.query.engine.impl.LuceneHSQuery.buildSearcher(LuceneHSQuery.java:475) ~[hibernate-search-engine-5.8.0.Beta4.jar:5.8.0.Beta4]
> 	at org.hibernate.search.query.engine.impl.LuceneHSQuery.buildSearcher(LuceneHSQuery.java:399) ~[hibernate-search-engine-5.8.0.Beta4.jar:5.8.0.Beta4]
> 	at org.hibernate.search.query.engine.impl.LuceneHSQuery.queryEntityInfos(LuceneHSQuery.java:142) ~[hibernate-search-engine-5.8.0.Beta4.jar:5.8.0.Beta4]
> 	at org.infinispan.query.impl.CacheQueryImpl.list(CacheQueryImpl.java:160) ~[classes/:?]
> 	at org.infinispan.query.blackbox.ClusteredCacheTest.testCompute(ClusteredCacheTest.java:687) ~[test-classes/:?]
> Caused by: org.apache.lucene.index.IndexNotFoundException: no segments* file found in InfinispanDirectory{indexName='person.194'}: files: []
> 	at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:726) ~[lucene-core-5.5.4.jar:5.5.4 31012120ebbd93744753eb37f1dbc5e654628291 - jpountz - 2017-02-08 19:08:03]
> 	at org.apache.lucene.index.SegmentInfos$FindSegmentsFile.run(SegmentInfos.java:683) ~[lucene-core-5.5.4.jar:5.5.4 31012120ebbd93744753eb37f1dbc5e654628291 - jpountz - 2017-02-08 19:08:03]
> 	at org.apache.lucene.index.SegmentInfos.readLatestCommit(SegmentInfos.java:490) ~[lucene-core-5.5.4.jar:5.5.4 31012120ebbd93744753eb37f1dbc5e654628291 - jpountz - 2017-02-08 19:08:03]
> 	at org.apache.lucene.index.StandardDirectoryReader.isCurrent(StandardDirectoryReader.java:344) ~[lucene-core-5.5.4.jar:5.5.4 31012120ebbd93744753eb37f1dbc5e654628291 - jpountz - 2017-02-08 19:08:03]
> 	at org.apache.lucene.index.StandardDirectoryReader.doOpenNoWriter(StandardDirectoryReader.java:300) ~[lucene-core-5.5.4.jar:5.5.4 31012120ebbd93744753eb37f1dbc5e654628291 - jpountz - 2017-02-08 19:08:03]
> 	at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:263) ~[lucene-core-5.5.4.jar:5.5.4 31012120ebbd93744753eb37f1dbc5e654628291 - jpountz - 2017-02-08 19:08:03]
> 	at org.apache.lucene.index.StandardDirectoryReader.doOpenIfChanged(StandardDirectoryReader.java:251) ~[lucene-core-5.5.4.jar:5.5.4 31012120ebbd93744753eb37f1dbc5e654628291 - jpountz - 2017-02-08 19:08:03]
> 	at org.apache.lucene.index.DirectoryReader.openIfChanged(DirectoryReader.java:137) ~[lucene-core-5.5.4.jar:5.5.4 31012120ebbd93744753eb37f1dbc5e654628291 - jpountz - 2017-02-08 19:08:03]
> 	at org.hibernate.search.indexes.impl.SharingBufferReaderProvider$PerDirectoryLatestReader.refreshAndGet(SharingBufferReaderProvider.java:239) ~[hibernate-search-engine-5.8.0.Beta4.jar:5.8.0.Beta4]
> 	... 35 more
> {noformat}
> I suspect the root problem is that trace logging makes everything slower.



--
This message was sent by Atlassian JIRA
(v7.5.0#75005)