Repository: iluwatar/java-design-patterns
Issue: ReaderWriterLock unit tests fail on CI
Labels: type: bug

Something wrong with the ReaderWriterLock unit tests.

See Travis builds:

https://travis-ci.org/iluwatar/java-design-patterns/builds/101906103
https://travis-ci.org/iluwatar/java-design-patterns/builds/101915400
https://travis-ci.org/iluwatar/java-design-patterns/builds/101917864


Issue comments:
From the log file of [Travis-Ci](https://api.travis-ci.org/jobs/101915401/log.txt?deansi=true), it pointouts that reader thread submited to the thread pool cannot  be executed in 149(99+50)ms. I suspect that the Travis-Ci has a high load and it can't assume the read can executed in accurate time.  I have revised the test case with another form. 

> Failed tests: 
>  ReaderAndWriterTest.testReadAndWrite:45 
> Wanted but not invoked:
> reader.read();
> -> at com.iluwatar.reader.writer.lock.ReaderAndWriterTest.testReadAndWrite(ReaderAndWriterTest.java:45)
> 
> However, there were other interactions with this mock:
> reader.run();
> -> at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)

``` java
  @Test
  public void testReadAndWrite() throws Exception {

    ReaderWriterLock lock = new ReaderWriterLock();

    Reader reader1 = spy(new Reader("Reader 1", lock.readLock()));
    Writer writer1 = spy(new Writer("Writer 1", lock.writeLock()));

    executeService.submit(reader1);
    // Let reader1 execute first
    Thread.sleep(50);
    executeService.submit(writer1);

45: verify(reader1, timeout(99).atLeastOnce()).read();
    verify(writer1, after(10).never()).write();
    verify(writer1, timeout(100).atLeastOnce()).write();

  }
```

@hoswey just create pull request when ready


Pull request review comments:

Patch that resolved the issue:
diff --git a/reader-writer-lock/src/main/java/com/iluwatar/reader/writer/lock/App.java b/reader-writer-lock/src/main/java/com/iluwatar/reader/writer/lock/App.java
index 1d02b6cadc96..b11b11be76ca 100644
--- a/reader-writer-lock/src/main/java/com/iluwatar/reader/writer/lock/App.java
+++ b/reader-writer-lock/src/main/java/com/iluwatar/reader/writer/lock/App.java
@@ -18,8 +18,7 @@
  * readers will be blocked until the writer is finished writing.
  * 
  * <p>
- * This example use two mutex to demonstrate the concurrent access of multiple readers and
- * writers.
+ * This example use two mutex to demonstrate the concurrent access of multiple readers and writers.
  * 
  * 
  * @author hongshuwei@gmail.com
@@ -33,15 +32,15 @@ public class App {
    */
   public static void main(String[] args) {
 
-    ExecutorService executeService = Executors.newFixedThreadPool(1000);
+    ExecutorService executeService = Executors.newFixedThreadPool(10);
     ReaderWriterLock lock = new ReaderWriterLock();
 
-    // Start 10 readers
-    IntStream.range(0, 10)
+    // Start 5 readers
+    IntStream.range(0, 5)
         .forEach(i -> executeService.submit(new Reader("Reader " + i, lock.readLock())));
 
-    // Start 10 writers
-    IntStream.range(0, 10)
+    // Start 5 writers
+    IntStream.range(0, 5)
         .forEach(i -> executeService.submit(new Writer("Writer " + i, lock.writeLock())));
     // In the system console, it can see that the read operations are executed concurrently while
     // write operations are exclusive.
diff --git a/reader-writer-lock/src/main/java/com/iluwatar/reader/writer/lock/Reader.java b/reader-writer-lock/src/main/java/com/iluwatar/reader/writer/lock/Reader.java
index 5704fdf28a81..214528080810 100644
--- a/reader-writer-lock/src/main/java/com/iluwatar/reader/writer/lock/Reader.java
+++ b/reader-writer-lock/src/main/java/com/iluwatar/reader/writer/lock/Reader.java
@@ -34,7 +34,7 @@ public void run() {
    */
   public void read() throws InterruptedException {
     System.out.println(name + " begin");
-    Thread.sleep(100);
+    Thread.sleep(250);
     System.out.println(name + " finish");
   }
 }
diff --git a/reader-writer-lock/src/main/java/com/iluwatar/reader/writer/lock/Writer.java b/reader-writer-lock/src/main/java/com/iluwatar/reader/writer/lock/Writer.java
index d7afa385a5c2..ae7b17080ab2 100644
--- a/reader-writer-lock/src/main/java/com/iluwatar/reader/writer/lock/Writer.java
+++ b/reader-writer-lock/src/main/java/com/iluwatar/reader/writer/lock/Writer.java
@@ -34,7 +34,7 @@ public void run() {
    */
   public void write() throws InterruptedException {
     System.out.println(name + " begin");
-    Thread.sleep(100);
+    Thread.sleep(250);
     System.out.println(name + " finish");
   }
 }


Test patch:
diff --git a/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/ReaderAndWriterTest.java b/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/ReaderAndWriterTest.java
index 3f3809be9b38..e29f578894b5 100644
--- a/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/ReaderAndWriterTest.java
+++ b/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/ReaderAndWriterTest.java
@@ -1,87 +1,81 @@
 package com.iluwatar.reader.writer.lock;
 
-import static org.mockito.Mockito.after;
-import static org.mockito.Mockito.spy;
-import static org.mockito.Mockito.timeout;
-import static org.mockito.Mockito.verify;
+import static org.mockito.Mockito.inOrder;
 
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
 import java.util.concurrent.TimeUnit;
 
-import org.junit.After;
-import org.junit.Before;
-import org.junit.Ignore;
 import org.junit.Test;
+import org.mockito.InOrder;
 
 /**
  * @author hongshuwei@gmail.com
  */
-public class ReaderAndWriterTest {
+public class ReaderAndWriterTest extends StdOutTest {
 
-  ExecutorService executeService;
 
-  @Before
-  public void setup() {
-    executeService = Executors.newFixedThreadPool(2);
-  }
 
   /**
    * Verify reader and writer can only get the lock to read and write orderly
    */
-  @Ignore // intermittent failures when executed on CI
   @Test
   public void testReadAndWrite() throws Exception {
 
     ReaderWriterLock lock = new ReaderWriterLock();
 
-    Reader reader1 = spy(new Reader("Reader 1", lock.readLock()));
-    Writer writer1 = spy(new Writer("Writer 1", lock.writeLock()));
+    Reader reader1 = new Reader("Reader 1", lock.readLock());
+    Writer writer1 = new Writer("Writer 1", lock.writeLock());
 
+    ExecutorService executeService = Executors.newFixedThreadPool(2);
     executeService.submit(reader1);
     // Let reader1 execute first
-    Thread.sleep(50);
+    Thread.sleep(150);
     executeService.submit(writer1);
 
-    verify(reader1, timeout(99).atLeastOnce()).read();
-    verify(writer1, after(10).never()).write();
-    verify(writer1, timeout(100).atLeastOnce()).write();
+    executeService.shutdown();
+    try {
+      executeService.awaitTermination(10, TimeUnit.SECONDS);
+    } catch (InterruptedException e) {
+      System.out.println("Error waiting for ExecutorService shutdown");
+    }
 
+    final InOrder inOrder = inOrder(getStdOutMock());
+    inOrder.verify(getStdOutMock()).println("Reader 1 begin");
+    inOrder.verify(getStdOutMock()).println("Reader 1 finish");
+    inOrder.verify(getStdOutMock()).println("Writer 1 begin");
+    inOrder.verify(getStdOutMock()).println("Writer 1 finish");
   }
 
   /**
    * Verify reader and writer can only get the lock to read and write orderly
    */
-  @Ignore // intermittent failures when executed on CI
   @Test
   public void testWriteAndRead() throws Exception {
 
     ExecutorService executeService = Executors.newFixedThreadPool(2);
     ReaderWriterLock lock = new ReaderWriterLock();
 
-    Reader reader1 = spy(new Reader("Reader 1", lock.readLock()));
-    Writer writer1 = spy(new Writer("Writer 1", lock.writeLock()));
+    Reader reader1 = new Reader("Reader 1", lock.readLock());
+    Writer writer1 = new Writer("Writer 1", lock.writeLock());
 
     executeService.submit(writer1);
-    // Let reader1 execute first
-    Thread.sleep(50);
+    // Let writer1 execute first
+    Thread.sleep(150);
     executeService.submit(reader1);
 
-    verify(writer1, timeout(99).atLeastOnce()).write();
-    verify(reader1, after(10).never()).read();
-    verify(reader1, timeout(100).atLeastOnce()).read();
-
-
-  }
-
-  @After
-  public void tearDown() {
     executeService.shutdown();
     try {
       executeService.awaitTermination(10, TimeUnit.SECONDS);
     } catch (InterruptedException e) {
       System.out.println("Error waiting for ExecutorService shutdown");
     }
+
+    final InOrder inOrder = inOrder(getStdOutMock());
+    inOrder.verify(getStdOutMock()).println("Writer 1 begin");
+    inOrder.verify(getStdOutMock()).println("Writer 1 finish");
+    inOrder.verify(getStdOutMock()).println("Reader 1 begin");
+    inOrder.verify(getStdOutMock()).println("Reader 1 finish");
   }
 }
 
diff --git a/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/ReaderTest.java b/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/ReaderTest.java
index f4cfbeb93403..e76fe29c249d 100644
--- a/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/ReaderTest.java
+++ b/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/ReaderTest.java
@@ -1,25 +1,23 @@
 package com.iluwatar.reader.writer.lock;
 
+import static org.mockito.Mockito.inOrder;
 import static org.mockito.Mockito.spy;
-import static org.mockito.Mockito.timeout;
-import static org.mockito.Mockito.verify;
 
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
 import java.util.concurrent.TimeUnit;
 
-import org.junit.Ignore;
 import org.junit.Test;
+import org.mockito.InOrder;
 
 /**
  * @author hongshuwei@gmail.com
  */
-public class ReaderTest {
+public class ReaderTest extends StdOutTest {
 
   /**
    * Verify that multiple readers can get the read lock concurrently
    */
-  @Ignore // intermittent failures when executed on CI
   @Test
   public void testRead() throws Exception {
 
@@ -30,18 +28,23 @@ public void testRead() throws Exception {
     Reader reader2 = spy(new Reader("Reader 2", lock.readLock()));
 
     executeService.submit(reader1);
+    Thread.sleep(150);
     executeService.submit(reader2);
 
-    // Read operation will hold the read lock 100 milliseconds, so here we guarantee that each
-    // readers can read in 99 milliseconds to prove that multiple read can perform in the same time.
-    verify(reader1, timeout(99).atLeastOnce()).read();
-    verify(reader2, timeout(99).atLeastOnce()).read();
-
     executeService.shutdown();
     try {
       executeService.awaitTermination(10, TimeUnit.SECONDS);
     } catch (InterruptedException e) {
       System.out.println("Error waiting for ExecutorService shutdown");
     }
+
+    // Read operation will hold the read lock 250 milliseconds, so here we prove that multiple reads
+    // can be performed in the same time.
+    final InOrder inOrder = inOrder(getStdOutMock());
+    inOrder.verify(getStdOutMock()).println("Reader 1 begin");
+    inOrder.verify(getStdOutMock()).println("Reader 2 begin");
+    inOrder.verify(getStdOutMock()).println("Reader 1 finish");
+    inOrder.verify(getStdOutMock()).println("Reader 2 finish");
+
   }
 }
diff --git a/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/StdOutTest.java b/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/StdOutTest.java
new file mode 100644
index 000000000000..762574b66bb0
--- /dev/null
+++ b/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/StdOutTest.java
@@ -0,0 +1,53 @@
+package com.iluwatar.reader.writer.lock;
+
+import org.junit.After;
+import org.junit.Before;
+
+import java.io.PrintStream;
+
+import static org.mockito.Mockito.mock;
+
+/**
+ * Date: 12/10/15 - 8:37 PM
+ *
+ * @author Jeroen Meulemeester
+ */
+public abstract class StdOutTest {
+
+  /**
+   * The mocked standard out {@link PrintStream}, required since some actions don't have any
+   * influence on accessible objects, except for writing to std-out using {@link System#out}
+   */
+  private final PrintStream stdOutMock = mock(PrintStream.class);
+
+  /**
+   * Keep the original std-out so it can be restored after the test
+   */
+  private final PrintStream stdOutOrig = System.out;
+
+  /**
+   * Inject the mocked std-out {@link PrintStream} into the {@link System} class before each test
+   */
+  @Before
+  public void setUp() {
+    System.setOut(this.stdOutMock);
+  }
+
+  /**
+   * Removed the mocked std-out {@link PrintStream} again from the {@link System} class
+   */
+  @After
+  public void tearDown() {
+    System.setOut(this.stdOutOrig);
+  }
+
+  /**
+   * Get the mocked stdOut {@link PrintStream}
+   *
+   * @return The stdOut print stream mock, renewed before each test
+   */
+  final PrintStream getStdOutMock() {
+    return this.stdOutMock;
+  }
+
+}
diff --git a/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/WriterTest.java b/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/WriterTest.java
index 97879025d59b..ed37bf3e51aa 100644
--- a/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/WriterTest.java
+++ b/reader-writer-lock/src/test/java/com/iluwatar/reader/writer/lock/WriterTest.java
@@ -1,26 +1,23 @@
 package com.iluwatar.reader.writer.lock;
 
-import static org.mockito.Mockito.after;
+import static org.mockito.Mockito.inOrder;
 import static org.mockito.Mockito.spy;
-import static org.mockito.Mockito.timeout;
-import static org.mockito.Mockito.verify;
 
 import java.util.concurrent.ExecutorService;
 import java.util.concurrent.Executors;
 import java.util.concurrent.TimeUnit;
 
-import org.junit.Ignore;
 import org.junit.Test;
+import org.mockito.InOrder;
 
 /**
  * @author hongshuwei@gmail.com
  */
-public class WriterTest {
+public class WriterTest extends StdOutTest {
 
   /**
    * Verify that multiple writers will get the lock in order.
    */
-  @Ignore // intermittent failures when executed on CI
   @Test
   public void testWrite() throws Exception {
 
@@ -32,23 +29,22 @@ public void testWrite() throws Exception {
 
     executeService.submit(writer1);
     // Let write1 execute first
-    Thread.sleep(50);
+    Thread.sleep(150);
     executeService.submit(writer2);
 
-    // Write operation will hold the write lock 100 milliseconds, so here we verify that when two
-    // write excute concurrently
-    // 1. The first write will get the lock and and write in 60ms
-    // 2. The second writer will cannot get the lock when first writer get the lock
-    // 3. The second writer will get the lock as last
-    verify(writer1, timeout(10).atLeastOnce()).write();
-    verify(writer2, after(10).never()).write();
-    verify(writer2, timeout(100).atLeastOnce()).write();
-
     executeService.shutdown();
     try {
       executeService.awaitTermination(10, TimeUnit.SECONDS);
     } catch (InterruptedException e) {
       System.out.println("Error waiting for ExecutorService shutdown");
     }
+    // Write operation will hold the write lock 250 milliseconds, so here we verify that when two
+    // writer execute concurrently, the second writer can only writes only when the first one is
+    // finished.
+    final InOrder inOrder = inOrder(getStdOutMock());
+    inOrder.verify(getStdOutMock()).println("Writer 1 begin");
+    inOrder.verify(getStdOutMock()).println("Writer 1 finish");
+    inOrder.verify(getStdOutMock()).println("Writer 2 begin");
+    inOrder.verify(getStdOutMock()).println("Writer 2 finish");
   }
 }