# HG changeset patch
# User Vladimir Kvashin <vkvashin@netbeans.org>
# Date 1480622980 -10800
# Branch release82
# Node ID e5b852e1920fa38b112c0bfd96ee36fbffed0854
# Parent  506cd546a8e9f330e83d207405b371416a0dcdb0
statistics for #269205 - 72-77% of time is spent in FilesystemInterceptorImpl.refreshRecursively

diff -r 506cd546a8e9 -r e5b852e1920f dlight.remote.impl/src/org/netbeans/modules/remote/impl/fs/RemoteDirectory.java
--- a/dlight.remote.impl/src/org/netbeans/modules/remote/impl/fs/RemoteDirectory.java	Thu Dec 01 17:05:45 2016 +0300
+++ b/dlight.remote.impl/src/org/netbeans/modules/remote/impl/fs/RemoteDirectory.java	Thu Dec 01 23:09:40 2016 +0300
@@ -63,6 +63,7 @@
 import java.util.concurrent.Future;
 import java.util.concurrent.TimeoutException;
 import java.util.concurrent.atomic.AtomicInteger;
+import java.util.concurrent.atomic.AtomicLong;
 import java.util.concurrent.locks.Lock;
 import java.util.logging.Level;
 import java.util.zip.ZipEntry;
@@ -521,13 +522,14 @@
             setFlag(CONNECTION_ISSUES, true);
         } catch (IOException ex) {
             RemoteLogger.info(ex, this); // undo won't show a red brick dialog, but print
-        }
+        } 
         return new RemoteFileObject[0];
     }
 
     private DirectoryStorage getDirectoryStorage(String childName) throws
             TimeoutException, ConnectException, IOException, InterruptedException, CancellationException, ExecutionException {
         long time = System.currentTimeMillis();
+        setFlag(MASK_INSIDE_GET_DIR_STORAGE, true);
         try {
             return getDirectoryStorageImpl(false, null, childName, false);
         } catch (StackOverflowError soe) { // workaround for #130929
@@ -535,8 +537,11 @@
             Exceptions.printStackTrace(new Exception(text, soe));
             throw new IOException(text, soe); // new IOException sic! this should never happen
         } finally {
+            setFlag(MASK_INSIDE_GET_DIR_STORAGE, false);
+            time = System.currentTimeMillis() - time;
+            reportTimeGDS(time);
             if (trace) {
-                trace("getDirectoryStorage for {1} took {0} ms", this, System.currentTimeMillis() - time); // NOI18N
+                trace("getDirectoryStorage for {1} took {0} ms", this, time); // NOI18N
             }
         }
     }
@@ -1357,6 +1362,7 @@
             // we check "org.netbeans.modules.masterfs.watcher.disable" property to be on par with masterfs,
             // which does the same and also sets this flag in tests 
             if (interceptor != null && !Boolean.getBoolean("org.netbeans.modules.masterfs.watcher.disable")) {
+                long time = System.currentTimeMillis();
                 try {
                     getFileSystem().setInsideVCS(true);
                     interceptor.refreshRecursively(FilesystemInterceptorProvider.toFileProxy(getOwnerFileObject()), 
@@ -1364,12 +1370,39 @@
 
                 } finally {
                     getFileSystem().setInsideVCS(false);
+                    time = System.currentTimeMillis() - time;
+                    reportTimeRR(time);
                 }
             }
             //fireFileChangedEvent(getListeners(), new FileEvent(this));
         }
         return storage;
     }
+    
+    private void reportTimeGDS(long time) {
+        if (time > 0 && RemoteLogger.isLoggable(Level.FINEST)) {
+            RemoteFileSystem fs = getFileSystem();
+            fs.dirStorageTime.addAndGet(time);
+            RemoteLogger.log(Level.FINEST,
+                    "#### GDS {0} {1} ms; Total GDS [{2}] {3} ms, including {4} in RR; total RR {5} ms", //NOI18N
+                    this.getPath(), time, getExecutionEnvironment(), fs.dirStorageTime, fs.dirStorageRR_VCSTime, fs.totalRR_VCSTime);
+        }        
+    }
+
+    private void reportTimeRR(long time) {
+        if (time > 0 && RemoteLogger.isLoggable(Level.FINEST)) {
+            if (time > 0) {
+                RemoteFileSystem fs = getFileSystem();
+                if (getFlag(MASK_INSIDE_GET_DIR_STORAGE)) {
+                    fs.dirStorageRR_VCSTime.addAndGet(time);
+                }
+                fs.totalRR_VCSTime.addAndGet(time);
+                RemoteLogger.log(Level.FINEST,
+                        "#### RR {0} {1} ms; [{2}] Inside GDS: {3}; total RR {4} ms", //NOI18N
+                        this.getPath(), time, getExecutionEnvironment(), fs.dirStorageRR_VCSTime, fs.totalRR_VCSTime);
+            }
+        }
+    }
 
     private void fireReadOnlyChangedEventsIfNeed(List<DirEntry> entriesToFireChangedRO) {
         for (DirEntry entry : entriesToFireChangedRO) {
diff -r 506cd546a8e9 -r e5b852e1920f dlight.remote.impl/src/org/netbeans/modules/remote/impl/fs/RemoteFileObjectBase.java
--- a/dlight.remote.impl/src/org/netbeans/modules/remote/impl/fs/RemoteFileObjectBase.java	Thu Dec 01 17:05:45 2016 +0300
+++ b/dlight.remote.impl/src/org/netbeans/modules/remote/impl/fs/RemoteFileObjectBase.java	Thu Dec 01 23:09:40 2016 +0300
@@ -104,6 +104,7 @@
     protected static final byte CONNECTION_ISSUES = 8;
     protected static final byte MASK_WARMUP = 16;
     protected static final byte MASK_CYCLIC_LINK = 32;
+    protected static final byte MASK_INSIDE_GET_DIR_STORAGE = 32;
 
     protected RemoteFileObjectBase(RemoteFileObject wrapper, RemoteFileSystem fileSystem, ExecutionEnvironment execEnv,
             RemoteFileObjectBase parent, String remotePath) {
diff -r 506cd546a8e9 -r e5b852e1920f dlight.remote.impl/src/org/netbeans/modules/remote/impl/fs/RemoteFileSystem.java
--- a/dlight.remote.impl/src/org/netbeans/modules/remote/impl/fs/RemoteFileSystem.java	Thu Dec 01 17:05:45 2016 +0300
+++ b/dlight.remote.impl/src/org/netbeans/modules/remote/impl/fs/RemoteFileSystem.java	Thu Dec 01 23:09:40 2016 +0300
@@ -61,6 +61,7 @@
 import java.util.concurrent.ExecutionException;
 import java.util.concurrent.atomic.AtomicBoolean;
 import java.util.concurrent.atomic.AtomicInteger;
+import java.util.concurrent.atomic.AtomicLong;
 import java.util.concurrent.locks.ReadWriteLock;
 import java.util.concurrent.locks.ReentrantReadWriteLock;
 import java.util.logging.Level;
@@ -148,6 +149,10 @@
 
     private final RequestProcessor.Task connectionTask;
 
+    /*package*/ final AtomicLong dirStorageTime = new AtomicLong(0);
+    /*package*/ final AtomicLong dirStorageRR_VCSTime = new AtomicLong(0);
+    /*package*/ final AtomicLong totalRR_VCSTime = new AtomicLong(0);
+
     /** 
      * ConnectionTaskLock is now scheduled not only upon connection change, but from ctor as well
      * (in order to get auto mounts).