This is an automated email from the ASF dual-hosted git repository.

thomasm pushed a commit to branch OAK-9561
in repository https://gitbox.apache.org/repos/asf/jackrabbit-oak.git

commit 0cd8f43ae212c1e53366281a286384a69930c71b
Author: thomasm <[email protected]>
AuthorDate: Wed Sep 1 11:46:37 2021 +0200

    OAK-9561 Flaky test: DelayedFacetReadTest.facet (investigation)
---
 oak-lucene/.gitignore                              |  1 +
 .../index/lucene/LuceneIndexNodeManager.java       |  5 +++-
 .../oak/plugins/index/lucene/hybrid/NRTIndex.java  | 21 ++++++++++++++++-
 .../index/lucene/hybrid/DelayedFacetReadTest.java  | 27 ++++++++++++++++++----
 4 files changed, 48 insertions(+), 6 deletions(-)

diff --git a/oak-lucene/.gitignore b/oak-lucene/.gitignore
new file mode 100644
index 0000000..ae3c172
--- /dev/null
+++ b/oak-lucene/.gitignore
@@ -0,0 +1 @@
+/bin/
diff --git 
a/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/LuceneIndexNodeManager.java
 
b/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/LuceneIndexNodeManager.java
index b55ac9b..8faecf1 100644
--- 
a/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/LuceneIndexNodeManager.java
+++ 
b/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/LuceneIndexNodeManager.java
@@ -240,11 +240,13 @@ public class LuceneIndexNodeManager {
 
         if (readers.size() == 1 && nrtReaders.isEmpty()){
             IndexReader reader = readers.get(0).getReader();
+System.out.println("incRef A");
             reader.incRef();
             return reader;
         }
         if (nrtReaders.size() == 1 && readers.isEmpty()){
             IndexReader reader = nrtReaders.get(0).getReader();
+System.out.println("incRef B");
             reader.incRef();
             return reader;
         }
@@ -298,7 +300,8 @@ public class LuceneIndexNodeManager {
         public SearcherHolder(IndexSearcher searcher, List<LuceneIndexReader> 
nrtReaders) {
             this.searcher = searcher;
             this.nrtReaders = nrtReaders;
-            this.indexStatistics = new 
LuceneIndexStatistics(searcher.getIndexReader());
+            IndexReader r = searcher.getIndexReader();
+            this.indexStatistics = new LuceneIndexStatistics(r);
         }
 
         public LuceneIndexStatistics getIndexStatistics() {
diff --git 
a/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/hybrid/NRTIndex.java
 
b/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/hybrid/NRTIndex.java
index 4e818de..8e3ea39 100644
--- 
a/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/hybrid/NRTIndex.java
+++ 
b/oak-lucene/src/main/java/org/apache/jackrabbit/oak/plugins/index/lucene/hybrid/NRTIndex.java
@@ -92,8 +92,11 @@ public class NRTIndex implements Closeable {
     private boolean closed;
     private boolean previousModeEnabled;
     private List<LuceneIndexReader> readers;
-    private final List<IndexReader> openedReaders;
+
+    // verify that all readers are closes when closing the NRTIndex
     private final boolean assertAllReadersClosed;
+    // array of opened readers, so that we can verify all readers are closed
+    private final List<IndexReader> openedReaders;
 
 
     public NRTIndex(LuceneIndexDefinition definition, IndexCopier indexCopier,
@@ -122,8 +125,13 @@ public class NRTIndex implements Closeable {
     private LuceneIndexReader getPrimaryReader() {
         DirectoryReader latestReader = createReader(dirReaderUsedForPrevious);
         while (latestReader != null && !latestReader.tryIncRef()) {
+;
+System.out.println("[" + Thread.currentThread().getName() + "] " + 
latestReader + " " + System.identityHashCode(latestReader) + " tryIncA -> " + 
latestReader.getRefCount()  );
             latestReader = createReader(dirReaderUsedForPrevious);
         }
+;
+System.out.println("[" + Thread.currentThread().getName() + "] " + 
latestReader + " " + System.identityHashCode(latestReader) + " tryIncB -> " + 
latestReader.getRefCount()  );
+new Exception().printStackTrace(System.out);
         if (latestReader != dirReaderUsedForPrevious) {
             decrementReaderUseCount(dirReaderUsedForPrevious);
             dirReaderUsedForPrevious = latestReader;
@@ -164,6 +172,10 @@ public class NRTIndex implements Closeable {
         if (previousReader != null) {
             newReaders.add(previousReader);
         }
+if (newReaders.size() > 1) {
+    System.out.println("0:" + System.identityHashCode(newReaders.get(0)));
+    System.out.println("1:" + System.identityHashCode(newReaders.get(1)));
+}
 
         decrementReaderUseCount(readers);
 
@@ -182,6 +194,7 @@ public class NRTIndex implements Closeable {
      * which refers to this NRTIndex as previous
      */
     public void disconnectPrevious(){
+System.out.println("disconnectPrevious!!!");
         decrementReaderUseCount(readers);
         readers = Collections.emptyList();
 
@@ -265,6 +278,7 @@ public class NRTIndex implements Closeable {
 
     private void assertAllReadersAreClosed() {
         for (IndexReader r : openedReaders){
+System.out.println("[" + Thread.currentThread().getName() + "] " + r + " " + 
System.identityHashCode(r) + " check -> " + r.getRefCount() );
             if (r.getRefCount() != 0){
                 String msg = String.format("Unclosed reader found with 
refCount %d for index %s", r.getRefCount(), toString());
                 throw new IllegalStateException(msg);
@@ -284,6 +298,8 @@ public class NRTIndex implements Closeable {
         try {
             if (reader != null) {
                 reader.decRef();
+System.out.println("[" + Thread.currentThread().getName() + "] " + reader + " 
" + System.identityHashCode(reader) + " defRef -> " + reader.getRefCount() );
+new Exception().printStackTrace(System.out);
             }
         } catch (IOException e) {
             log.warn("[{}] Error occurred while releasing reader instance {}",
@@ -313,12 +329,15 @@ public class NRTIndex implements Closeable {
             } else {
                 DirectoryReader newReader = 
DirectoryReader.openIfChanged(dirReader, indexWriter, false);
                 if (newReader != null) {
+System.out.println("[" + Thread.currentThread().getName() + "] 
openIfChanged!");
                     result = newReader;
                 }
             }
             ctx.stop();
 
             if (assertAllReadersClosed && result != null && result != 
dirReader) {
+System.out.println("[" + Thread.currentThread().getName() + "] " + result + " 
" + System.identityHashCode(result) + " open reader -> " + 
result.getRefCount());
+new Exception().printStackTrace(System.out);
                 openedReaders.add(result);
             }
 
diff --git 
a/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/hybrid/DelayedFacetReadTest.java
 
b/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/hybrid/DelayedFacetReadTest.java
index c33270e..5a9b870 100644
--- 
a/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/hybrid/DelayedFacetReadTest.java
+++ 
b/oak-lucene/src/test/java/org/apache/jackrabbit/oak/plugins/index/lucene/hybrid/DelayedFacetReadTest.java
@@ -60,6 +60,7 @@ import org.junit.Test;
 import org.junit.rules.TemporaryFolder;
 
 import javax.jcr.GuestCredentials;
+import javax.jcr.NodeIterator;
 import javax.jcr.Repository;
 import javax.jcr.RepositoryException;
 import javax.jcr.Session;
@@ -111,13 +112,19 @@ public class DelayedFacetReadTest extends 
AbstractQueryTest {
 
     @After
     public void tearDown() throws IOException {
+System.out.println("main close");
         luceneIndexProvider.close();
-        try {
-            thread.join();
-        } catch (InterruptedException e) {
-            e.printStackTrace();
+System.out.println("main closed");
+        if (thread != null) {
+            try {
+                thread.join();
+            } catch (InterruptedException e) {
+                e.printStackTrace();
+            }
         }
+System.out.println("main closed2");
         new ExecutorCloser(executorService).close();
+System.out.println("main closed3");
         nrtIndexFactory.close();
         // restore original system properties i.e. before test started
         System.setProperties(backupProperties);
@@ -219,13 +226,24 @@ public class DelayedFacetReadTest extends 
AbstractQueryTest {
                 try {
                     clock.waitUntil(clock.getTime() + REFRESH_DELTA + 1);
                     q = qm.createQuery("SELECT [rep:facet(foo)] FROM [nt:base] 
WHERE [cons] = 'val'", SQL2);
+System.out.println("a...");
+// Thread.sleep(1000);
+System.out.println("ab..");
                     QueryResult qr = q.execute();
+                    NodeIterator it = qr.getNodes();
+                    while (it.hasNext()) {
+                        it.nextNode();
+                    }
+System.out.println("abc..");
                 } catch (RepositoryException | InterruptedException e) {
                     e.printStackTrace();
                 }
             }
         });
+
+
         thread.start();
+System.out.println("main A");
         try {
             RowIterator it = qr.getRows();
             String firstColumnName = qr.getColumnNames()[0];
@@ -236,6 +254,7 @@ public class DelayedFacetReadTest extends AbstractQueryTest 
{
             e.printStackTrace();
             throw e;
         }
+System.out.println("main B");
     }
 
     private void runAsyncIndex() {

Reply via email to