Fixing PathWatcher and Test

Using a trigger file (and event type) in test cases to know
when the watching & capture is truely finished (instead of
using sleep waits)

jetty-util/src/main/java/org/eclipse/jetty/util/PathWatcher.java

@@ -62,26 +62,6 @@ import org.eclipse.jetty.util.log.Logger;
  */
 public class PathWatcher extends AbstractLifeCycle implements Runnable
 {
-    /**
-     * Set to true to enable super noisy debug logging
-     */
-    private static final boolean NOISY = false;
-    
-    private static final boolean IS_WINDOWS;
-    
-    static
-    {
-        String os = System.getProperty("os.name");
-        if (os == null)
-        {
-            IS_WINDOWS = false;
-        }
-        else
-        {
-            IS_WINDOWS = os.toLowerCase(Locale.ENGLISH).contains("windows");
-        }
-    }
-
     public static class Config
     {
         private static final String PATTERN_SEP;
@@ -288,12 +268,18 @@ public class PathWatcher extends AbstractLifeCycle implements Runnable
             {
                 if (matcher.matches(path))
                 {
-                    if(NOISY) LOG.debug("Matched TRUE on {}",path);
+                    if (NOISY_LOG.isDebugEnabled())
+                    {
+                        NOISY_LOG.debug("Matched TRUE on {}",path);
+                    }
                     return true;
                 }
             }
 
-            if(NOISY) LOG.debug("Matched FALSE on {}",path);
+            if (NOISY_LOG.isDebugEnabled())
+            {
+                NOISY_LOG.debug("Matched FALSE on {}",path);
+            }
             return false;
         }
 
@@ -353,7 +339,8 @@ public class PathWatcher extends AbstractLifeCycle implements Runnable
         }
 
         /**
-         * Determine if the provided child directory should be recursed into based on the configured {@link #setRecurseDepth(int)}
+         * Determine if the provided child directory should be recursed into based on the configured
+         * {@link #setRecurseDepth(int)}
          *
          * @param child
          *            the child directory to test against
@@ -376,11 +363,14 @@ public class PathWatcher extends AbstractLifeCycle implements Runnable
             StringBuilder s = new StringBuilder();
             s.append("glob:");
 
+            boolean needDelim = false;
+
+            // Add root (aka "C:\" for Windows)
             if (path.getRoot() != null)
             {
                 for (char c : path.getRoot().toString().toCharArray())
                 {
-                    if (c == '\\')
+                    if (c != '\\')
                     {
                         s.append(PATTERN_SEP);
                     }
@@ -390,22 +380,39 @@ public class PathWatcher extends AbstractLifeCycle implements Runnable
                     }
                 }
             }
-
+            else
-            for (Path segment : path)
             {
-                s.append(segment);
+                needDelim = true;
-                s.append(PATTERN_SEP);
             }
 
-            for (char c : subPattern.toCharArray())
+            // Add the individual path segments
+            for (Path segment : path)
             {
-                if (c == '/')
+                if (needDelim)
                 {
                     s.append(PATTERN_SEP);
                 }
-                else
+                s.append(segment);
+                needDelim = true;
+            }
+
+            // Add the sub pattern (if specified)
+            if ((subPattern != null) && (subPattern.length() > 0))
+            {
+                if (needDelim)
                 {
-                    s.append(c);
+                    s.append(PATTERN_SEP);
+                }
+                for (char c : subPattern.toCharArray())
+                {
+                    if (c == '/')
+                    {
+                        s.append(PATTERN_SEP);
+                    }
+                    else
+                    {
+                        s.append(c);
+                    }
                 }
             }
 
@@ -553,8 +560,8 @@ public class PathWatcher extends AbstractLifeCycle implements Runnable
         {
             final int prime = 31;
             int result = 1;
-            result = (prime * result) + ((path == null)?0:path.hashCode());
+            result = (prime * result) + ((path == null) ? 0 : path.hashCode());
-            result = (prime * result) + ((type == null)?0:type.hashCode());
+            result = (prime * result) + ((type == null) ? 0 : type.hashCode());
             return result;
         }
 
@@ -578,7 +585,26 @@ public class PathWatcher extends AbstractLifeCycle implements Runnable
         UNKNOWN;
     }
 
+    private static final boolean IS_WINDOWS;
+
+    static
+    {
+        String os = System.getProperty("os.name");
+        if (os == null)
+        {
+            IS_WINDOWS = false;
+        }
+        else
+        {
+            IS_WINDOWS = os.toLowerCase(Locale.ENGLISH).contains("windows");
+        }
+    }
+
     private static final Logger LOG = Log.getLogger(PathWatcher.class);
+    /**
+     * super noisy debug logging
+     */
+    private static final Logger NOISY_LOG = Log.getLogger(PathWatcher.class.getName() + ".Noisy");
 
     @SuppressWarnings("unchecked")
     protected static <T> WatchEvent<T> cast(WatchEvent<?> event)
@@ -813,13 +839,19 @@ public class PathWatcher extends AbstractLifeCycle implements Runnable
                 // Process new events
                 if (pendingUpdateEvents.isEmpty())
                 {
-                    if(NOISY) LOG.debug("Waiting for take()");
+                    if (NOISY_LOG.isDebugEnabled())
+                    {
+                        NOISY_LOG.debug("Waiting for take()");
+                    }
                     // wait for any event
                     key = watcher.take();
                 }
                 else
                 {
-                    if(NOISY) LOG.debug("Waiting for poll({}, {})",updateQuietTimeDuration,updateQuietTimeUnit);
+                    if (NOISY_LOG.isDebugEnabled())
+                    {
+                        NOISY_LOG.debug("Waiting for poll({}, {})",updateQuietTimeDuration,updateQuietTimeUnit);
+                    }
                     key = watcher.poll(updateQuietTimeDuration,updateQuietTimeUnit);
                     if (key == null)
                     {
@@ -948,7 +980,7 @@ public class PathWatcher extends AbstractLifeCycle implements Runnable
     {
         long desiredMillis = unit.toMillis(duration);
 
-        if (IS_WINDOWS && desiredMillis < 1000)
+        if (IS_WINDOWS && (desiredMillis < 1000))
         {
             LOG.warn("Quiet Time is too low for Microsoft Windows: {} < 1000 ms (defaulting to 1000 ms)",desiredMillis);
             this.updateQuietTimeDuration = 1000;

jetty-util/src/test/java/org/eclipse/jetty/util/PathWatcherTest.java

@@ -18,17 +18,10 @@
 
 package org.eclipse.jetty.util;
 
-import static java.nio.file.StandardOpenOption.CREATE;
+import static org.eclipse.jetty.util.PathWatcher.PathWatchEventType.*;
-import static java.nio.file.StandardOpenOption.TRUNCATE_EXISTING;
+import static org.hamcrest.Matchers.*;
-import static java.nio.file.StandardOpenOption.WRITE;
+import static org.junit.Assert.*;
-import static org.eclipse.jetty.util.PathWatcher.PathWatchEventType.ADDED;
-import static org.eclipse.jetty.util.PathWatcher.PathWatchEventType.DELETED;
-import static org.eclipse.jetty.util.PathWatcher.PathWatchEventType.MODIFIED;
-import static org.hamcrest.Matchers.contains;
-import static org.hamcrest.Matchers.is;
-import static org.junit.Assert.assertThat;
 
-import java.io.BufferedWriter;
 import java.io.File;
 import java.io.FileOutputStream;
 import java.io.IOException;
@@ -40,6 +33,7 @@ import java.util.Arrays;
 import java.util.HashMap;
 import java.util.List;
 import java.util.Map;
+import java.util.concurrent.CountDownLatch;
 import java.util.concurrent.TimeUnit;
 
 import org.eclipse.jetty.toolchain.test.FS;
@@ -49,15 +43,14 @@ import org.eclipse.jetty.util.PathWatcher.PathWatchEvent;
 import org.eclipse.jetty.util.PathWatcher.PathWatchEventType;
 import org.eclipse.jetty.util.log.Log;
 import org.eclipse.jetty.util.log.Logger;
-import org.junit.Ignore;
 import org.junit.Rule;
 import org.junit.Test;
 
-@Ignore("Temporary ignore until all platforms are tested")
 public class PathWatcherTest
 {
     public static class PathWatchEventCapture implements PathWatcher.Listener
     {
+        public final static String FINISH_TAG = "#finished#.tag";
         private static final Logger LOG = Log.getLogger(PathWatcherTest.PathWatchEventCapture.class);
         private final Path baseDir;
 
@@ -66,6 +59,10 @@ public class PathWatcherTest
          */
         public Map<String, List<PathWatchEventType>> events = new HashMap<>();
 
+        public CountDownLatch finishedLatch = new CountDownLatch(1);
+        private PathWatchEventType triggerType;
+        private Path triggerPath;
+
         public PathWatchEventCapture(Path baseDir)
         {
             this.baseDir = baseDir;
@@ -76,6 +73,15 @@ public class PathWatcherTest
         {
             synchronized (events)
             {
+                if (triggerPath != null)
+                {
+                    if (triggerPath.equals(event.getPath()) && (event.getType() == triggerType))
+                    {
+                        LOG.debug("Encountered finish trigger: {} on {}",event.getType(),event.getPath());
+                        finishedLatch.countDown();
+                    }
+                }
+
                 Path relativePath = this.baseDir.relativize(event.getPath());
                 String key = relativePath.toString().replace(File.separatorChar,'/');
 
@@ -131,14 +137,52 @@ public class PathWatcherTest
                 assertThat("Events for path [" + relativePath + "]",actualEvents,contains(expectedEvents));
             }
         }
+
+        /**
+         * Set the path and type that will trigger this capture to be finished
+         * 
+         * @param triggerPath
+         *            the trigger path we look for to know that the capture is complete
+         * @param triggerType
+         *            the trigger type we look for to know that the capture is complete
+         */
+        public void setFinishTrigger(Path triggerPath, PathWatchEventType triggerType)
+        {
+            this.triggerPath = triggerPath;
+            this.triggerType = triggerType;
+            LOG.debug("Setting finish trigger {} for path {}",triggerType,triggerPath);
+        }
+
+        /**
+         * Await the countdown latch on the finish trigger
+         * 
+         * @param pathWatcher
+         *            the watcher instance we are waiting on
+         * @throws IOException
+         *             if unable to create the finish tag file
+         * @throws InterruptedException
+         *             if unable to await the finish of the run
+         * @see #setFinishTrigger(Path, PathWatchEventType)
+         */
+        public void awaitFinish(PathWatcher pathWatcher) throws IOException, InterruptedException
+        {
+            assertThat("Trigger Path must be set",triggerPath,notNullValue());
+            assertThat("Trigger Type must be set",triggerType,notNullValue());
+            double multiplier = 8.0;
+            long awaitMillis = (long)((double)pathWatcher.getUpdateQuietTimeMillis() * multiplier);
+            LOG.debug("Waiting for finish ({} ms)",awaitMillis);
+            assertThat("Timed Out (" + awaitMillis + "ms) waiting for capture to finish",finishedLatch.await(awaitMillis,TimeUnit.MILLISECONDS),is(true));
+            LOG.debug("Finished capture");
+        }
     }
 
     private static void updateFile(Path path, String newContents) throws IOException
     {
-        try (BufferedWriter writer = Files.newBufferedWriter(path,StandardCharsets.UTF_8,CREATE,TRUNCATE_EXISTING,WRITE))
+        try (FileOutputStream out = new FileOutputStream(path.toFile()))
         {
-            writer.append(newContents);
+            out.write(newContents.getBytes(StandardCharsets.UTF_8));
-            writer.flush();
+            out.flush();
+            out.getFD().sync();
         }
     }
 
@@ -196,16 +240,19 @@ public class PathWatcherTest
 
     /**
      * Sleep longer than the quiet time.
-     * @param pathWatcher the path watcher to inspect for its quiet time
+     * 
-     * @throws InterruptedException if unable to sleep
+     * @param pathWatcher
+     *            the path watcher to inspect for its quiet time
+     * @throws InterruptedException
+     *             if unable to sleep
      */
     private static void awaitQuietTime(PathWatcher pathWatcher) throws InterruptedException
     {
-        double multiplier = 1.5;
+        double multiplier = 2.0;
         if (OS.IS_WINDOWS)
         {
             // Microsoft Windows filesystem is too slow for a lower multiplier
-            multiplier = 2.5;
+            multiplier = 3.0;
         }
         TimeUnit.MILLISECONDS.sleep((long)((double)pathWatcher.getUpdateQuietTimeMillis() * multiplier));
     }
@@ -358,19 +405,24 @@ public class PathWatcherTest
             awaitQuietTime(pathWatcher);
 
             // Update web.xml
-            updateFile(dir.resolve("bar/WEB-INF/web.xml"),"Hello Update");
+            Path webFile = dir.resolve("bar/WEB-INF/web.xml");
-            FS.touch(dir.resolve("bar/WEB-INF/web.xml").toFile());
+            capture.setFinishTrigger(webFile,MODIFIED);
+            updateFile(webFile,"Hello Update");
 
             // Delete war
             Files.delete(dir.resolve("foo.war"));
 
-            // Let quiet time elapse
+            // Add a another new war
-            awaitQuietTime(pathWatcher);
+            Files.createFile(dir.resolve("bar.war"));
+
+            // Let capture complete
+            capture.awaitFinish(pathWatcher);
 
             Map<String, PathWatchEventType[]> expected = new HashMap<>();
 
             expected.put("bar/WEB-INF/web.xml",new PathWatchEventType[] { ADDED, MODIFIED });
             expected.put("foo.war",new PathWatchEventType[] { ADDED, DELETED });
+            expected.put("bar.war",new PathWatchEventType[] { ADDED });
 
             capture.assertEvents(expected);
         }
@@ -413,10 +465,12 @@ public class PathWatcherTest
             awaitQuietTime(pathWatcher);
 
             // New war added
-            updateFile(dir.resolve("hello.war"),"Hello Update");
+            Path warFile = dir.resolve("hello.war");
+            capture.setFinishTrigger(warFile,MODIFIED);
+            updateFile(warFile,"Hello Update");
 
-            // Let quiet time elapse
+            // Let capture finish
-            awaitQuietTime(pathWatcher);
+            capture.awaitFinish(pathWatcher);
 
             Map<String, PathWatchEventType[]> expected = new HashMap<>();
 
@@ -453,7 +507,7 @@ public class PathWatcherTest
         Files.createFile(dir.resolve("bar/WEB-INF/web.xml"));
 
         PathWatcher pathWatcher = new PathWatcher();
-        pathWatcher.setUpdateQuietTime(300,TimeUnit.MILLISECONDS);
+        pathWatcher.setUpdateQuietTime(500,TimeUnit.MILLISECONDS);
 
         // Add listener
         PathWatchEventCapture capture = new PathWatchEventCapture(dir);
@@ -475,10 +529,12 @@ public class PathWatcherTest
             awaitQuietTime(pathWatcher);
 
             // New war added (slowly)
-            updateFileOverTime(dir.resolve("hello.war"),50 * MB,3,TimeUnit.SECONDS);
+            Path warFile = dir.resolve("hello.war");
+            capture.setFinishTrigger(warFile,MODIFIED);
+            updateFileOverTime(warFile,50 * MB,3,TimeUnit.SECONDS);
 
-            // Let quiet time elapse
+            // Let capture finish
-            awaitQuietTime(pathWatcher);
+            capture.awaitFinish(pathWatcher);
 
             Map<String, PathWatchEventType[]> expected = new HashMap<>();
 

jetty-util/src/test/resources/jetty-logging.properties

@@ -1,3 +1,5 @@
 # Setup default logging implementation for during testing
 org.eclipse.jetty.util.log.class=org.eclipse.jetty.util.log.StdErrLog
 #org.eclipse.jetty.util.LEVEL=DEBUG
+
+org.eclipse.jetty.util.PathWatcher.Noisy.LEVEL=OFF