From b84529a89ccecaf360ea93b2a014037ee399c69c Mon Sep 17 00:00:00 2001
From: Eugene Zhuravlev <jeka@intellij.com>
Date: Thu, 14 Feb 2013 21:32:56 +0100
Subject: [PATCH] external build: additional logging

---
 .../org/jetbrains/jps/cmdline/BuildMain.java  | 10 ++++---
 .../jetbrains/jps/cmdline/BuildSession.java   | 27 ++++++++++++-------
 .../jetbrains/jps/incremental/fs/FSState.java |  8 ++++++
 3 files changed, 33 insertions(+), 12 deletions(-)

diff --git a/jps/jps-builders/src/org/jetbrains/jps/cmdline/BuildMain.java b/jps/jps-builders/src/org/jetbrains/jps/cmdline/BuildMain.java
index 56985a2f8c11..0ff34899e1ac 100644
--- a/jps/jps-builders/src/org/jetbrains/jps/cmdline/BuildMain.java
+++ b/jps/jps-builders/src/org/jetbrains/jps/cmdline/BuildMain.java
@@ -45,7 +45,13 @@ import java.util.UUID;
 public class BuildMain {
   public static final Key<String> FORCE_MODEL_LOADING_PARAMETER = Key.create("_force_model_loading");
   private static final String LOG_FILE_NAME = "log.xml";
-  private static final Logger LOG = Logger.getInstance("#org.jetbrains.jps.cmdline.BuildMain");
+
+  private static final Logger LOG;
+  static {
+    initLoggers();
+    LOG = Logger.getInstance("#org.jetbrains.jps.cmdline.BuildMain");
+  }
+
   private static NioClientSocketChannelFactory ourChannelFactory;
 
   public static void main(String[] args){
@@ -56,8 +62,6 @@ public class BuildMain {
     final File systemDir = new File(FileUtil.toCanonicalPath(args[3]));
     Utils.setSystemRoot(systemDir);
 
-    initLoggers();
-
     ourChannelFactory = new NioClientSocketChannelFactory(SharedThreadPool.getInstance(), SharedThreadPool.getInstance(), 1);
     final ClientBootstrap bootstrap = new ClientBootstrap(ourChannelFactory);
     bootstrap.setPipelineFactory(new ChannelPipelineFactory() {
diff --git a/jps/jps-builders/src/org/jetbrains/jps/cmdline/BuildSession.java b/jps/jps-builders/src/org/jetbrains/jps/cmdline/BuildSession.java
index e41a788e44e0..c70d2284dedc 100644
--- a/jps/jps-builders/src/org/jetbrains/jps/cmdline/BuildSession.java
+++ b/jps/jps-builders/src/org/jetbrains/jps/cmdline/BuildSession.java
@@ -301,23 +301,25 @@ final class BuildSession implements Runnable, CanceledStatus {
           pd.getFSCache().clear();
           cacheCleared = true;
         }
-        if (Utils.IS_TEST_MODE) {
-          LOG.info("Applying deleted path from fs event: " + file.getPath());
+        if (LOG.isDebugEnabled()) {
+          LOG.debug("Applying deleted path from fs event: " + file.getPath());
         }
         for (BuildRootDescriptor rootDescriptor : descriptor) {
           pd.fsState.registerDeleted(rootDescriptor.getTarget(), file, timestamps);
         }
       }
-      else if (Utils.IS_TEST_MODE) {
-        LOG.info("Skipping deleted path: " + file.getPath());
+      else {
+        if (LOG.isDebugEnabled()) {
+          LOG.debug("Skipping deleted path: " + file.getPath());
+        }
       }
     }
     for (String changed : event.getChangedPathsList()) {
       final File file = new File(changed);
       Collection<BuildRootDescriptor> descriptors = pd.getBuildRootIndex().findAllParentDescriptors(file, null, null);
       if (!descriptors.isEmpty()) {
-        if (Utils.IS_TEST_MODE) {
-          LOG.info("Applying dirty path from fs event: " + file.getPath());
+        if (LOG.isDebugEnabled()) {
+          LOG.debug("Applying dirty path from fs event: " + changed);
         }
         long fileStamp = -1L;
         for (BuildRootDescriptor descriptor : descriptors) {
@@ -325,7 +327,7 @@ final class BuildSession implements Runnable, CanceledStatus {
             if (fileStamp == -1L) {
               fileStamp = FileSystemUtil.lastModified(file); // lazy init
             }
-            long stamp = timestamps.getStamp(file, descriptor.getTarget());
+            final long stamp = timestamps.getStamp(file, descriptor.getTarget());
             if (stamp != fileStamp) {
               if (!cacheCleared) {
                 pd.getFSCache().clear();
@@ -333,11 +335,18 @@ final class BuildSession implements Runnable, CanceledStatus {
               }
               pd.fsState.markDirty(null, file, descriptor, timestamps, saveEventStamp);
             }
+            else {
+              if (LOG.isDebugEnabled()) {
+                LOG.debug(descriptor.getTarget() + ": Path considered up-to-date: " + changed + "; timestamp= " + stamp);
+              }
+            }
           }
         }
       }
-      else if (Utils.IS_TEST_MODE) {
-        LOG.info("Skipping dirty path: " + file.getPath());
+      else {
+        if (LOG.isDebugEnabled()) {
+          LOG.debug("Skipping dirty path: " + file.getPath());
+        }
       }
     }
   }
diff --git a/jps/jps-builders/src/org/jetbrains/jps/incremental/fs/FSState.java b/jps/jps-builders/src/org/jetbrains/jps/incremental/fs/FSState.java
index 462b8eaf027e..cc16f3ac7539 100644
--- a/jps/jps-builders/src/org/jetbrains/jps/incremental/fs/FSState.java
+++ b/jps/jps-builders/src/org/jetbrains/jps/incremental/fs/FSState.java
@@ -102,6 +102,9 @@ public class FSState {
   public boolean markDirty(@Nullable CompileContext context, final File file, final BuildRootDescriptor rd, final @Nullable Timestamps tsStorage, boolean saveEventStamp) throws IOException {
     final boolean marked = getDelta(rd.getTarget()).markRecompile(rd, file);
     if (marked) {
+      if (LOG.isDebugEnabled()) {
+        LOG.debug(rd.getTarget() + ": MARKED DIRTY: " + file.getPath());
+      }
       if (saveEventStamp) {
         myRegistrationStamps.put(file, System.currentTimeMillis());
       }
@@ -109,6 +112,11 @@ public class FSState {
         tsStorage.removeStamp(file, rd.getTarget());
       }
     }
+    else {
+      if (LOG.isDebugEnabled()) {
+        LOG.debug(rd.getTarget() + ": NOT MARKED DIRTY: " + file.getPath());
+      }
+    }
     return marked;
   }