SONAR-6770 Improve logging of cache usage

sonar-batch/src/main/java/org/sonar/batch/bootstrap/AbstractServerLoader.java

@@ -0,0 +1,31 @@
+/*
+ * SonarQube, open source software quality management tool.
+ * Copyright (C) 2008-2014 SonarSource
+ * mailto:contact AT sonarsource DOT com
+ *
+ * SonarQube is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU Lesser General Public
+ * License as published by the Free Software Foundation; either
+ * version 3 of the License, or (at your option) any later version.
+ *
+ * SonarQube is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+ * Lesser General Public License for more details.
+ *
+ * You should have received a copy of the GNU Lesser General Public License
+ * along with this program; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
+ */
+package org.sonar.batch.bootstrap;
+
+public class AbstractServerLoader {
+  protected Boolean loadedFromCache = null;
+
+  public boolean loadedFromCache() {
+    if (loadedFromCache == null) {
+      throw new IllegalStateException("Didn't load");
+    }
+    return loadedFromCache;
+  }
+}

sonar-batch/src/main/java/org/sonar/batch/bootstrap/BatchPluginInstaller.java

@@ -19,8 +19,6 @@
  */
 package org.sonar.batch.bootstrap;
 
-import com.google.common.io.Files;
-
 import com.google.common.annotations.VisibleForTesting;
 import com.google.common.collect.Lists;
 
@@ -54,25 +52,33 @@ public class BatchPluginInstaller implements PluginInstaller {
   private final WSLoader wsLoader;
   private final FileCache fileCache;
   private final BatchPluginPredicate pluginPredicate;
+  private final ServerClient serverClient;
 
-  public BatchPluginInstaller(WSLoader wsLoader, FileCache fileCache, BatchPluginPredicate pluginPredicate) {
+  public BatchPluginInstaller(WSLoader wsLoader, ServerClient serverClient, FileCache fileCache, BatchPluginPredicate pluginPredicate) {
     this.wsLoader = wsLoader;
     this.fileCache = fileCache;
     this.pluginPredicate = pluginPredicate;
+    this.serverClient = serverClient;
   }
 
   @Override
   public Map<String, PluginInfo> installRemotes() {
+    return loadPlugins(listRemotePlugins());
+  }
+
+  private Map<String, PluginInfo> loadPlugins(List<RemotePlugin> remotePlugins) {
     Map<String, PluginInfo> infosByKey = new HashMap<>();
-    List<RemotePlugin> remotePlugins = listRemotePlugins();
+
     Profiler profiler = Profiler.create(LOG).startDebug("Load plugins");
+
     for (RemotePlugin remotePlugin : remotePlugins) {
       if (pluginPredicate.apply(remotePlugin.getKey())) {
         File jarFile = download(remotePlugin);
         PluginInfo info = PluginInfo.create(jarFile);
         infosByKey.put(info.getKey(), info);
       }
     }
+
     profiler.stopDebug();
     return infosByKey;
   }
@@ -100,7 +106,7 @@ public void download(String filename, File toFile) throws IOException {
             LOG.info("Download {}", file.getFilename());
           }
 
-          Files.write(wsLoader.load(url), toFile);
+          serverClient.download(url, toFile);
         }
       });
 
@@ -115,10 +121,8 @@ public void download(String filename, File toFile) throws IOException {
   @VisibleForTesting
   List<RemotePlugin> listRemotePlugins() {
     try {
-      Profiler profiler = Profiler.create(LOG).startInfo("Load plugins index");
-      String indexContent = wsLoader.loadString(PLUGINS_INDEX_URL);
-      profiler.stopInfo();
-      String[] rows = StringUtils.split(indexContent, CharUtils.LF);
+      String pluginIndex = loadPluginIndex();
+      String[] rows = StringUtils.split(pluginIndex, CharUtils.LF);
       List<RemotePlugin> result = Lists.newArrayList();
       for (String row : rows) {
         result.add(RemotePlugin.unmarshal(row));
@@ -129,4 +133,18 @@ List<RemotePlugin> listRemotePlugins() {
       throw new IllegalStateException("Fail to load plugin index: " + PLUGINS_INDEX_URL, e);
     }
   }
+
+  private String loadPluginIndex() {
+    Profiler profiler = Profiler.create(LOG).startInfo("Load plugins index");
+    WSLoaderResult<String> wsResult = wsLoader.loadString(PLUGINS_INDEX_URL);
+
+    if (wsResult.isFromCache()) {
+      profiler.stopInfo("Load plugins index (done from cache)");
+    } else {
+      profiler.stopInfo();
+    }
+
+    return wsResult.get();
+  }
+
 }

sonar-batch/src/main/java/org/sonar/batch/bootstrap/ServerClient.java

@@ -107,7 +107,7 @@ public String downloadString(String pathStartingWithSlash, String requestMethod,
 
   /**
    * @throws IllegalStateException on I/O error, not limited to the network connection and if HTTP response code > 400 and wrapHttpException is true
-   * @throws HttpException if HTTP response code > 400 and wrapHttpException is false
+   * @throws HttpDownloader.HttpException if HTTP response code > 400 and wrapHttpException is false
    */
   public InputStream load(String pathStartingWithSlash, String requestMethod, boolean wrapHttpException, @Nullable Integer connectTimeoutMs,
     @Nullable Integer readTimeoutMs) {

sonar-batch/src/main/java/org/sonar/batch/bootstrap/WSLoader.java

@@ -19,6 +19,9 @@
  */
 package org.sonar.batch.bootstrap;
 
+import org.sonar.api.utils.log.Logger;
+import org.sonar.api.utils.log.Loggers;
+
 import javax.annotation.Nonnull;
 
 import org.sonar.api.utils.HttpDownloader;
@@ -34,6 +37,7 @@
 import org.sonar.home.cache.PersistentCache;
 
 public class WSLoader {
+  private static final Logger LOG = Loggers.get(WSLoader.class);
   private static final String FAIL_MSG = "Server is not accessible and data is not cached";
   private static final int CONNECT_TIMEOUT = 5000;
   private static final int READ_TIMEOUT = 10000;
@@ -65,16 +69,20 @@ public WSLoader(PersistentCache cache, ServerClient client) {
     this(false, cache, client);
   }
 
-  public ByteSource loadSource(String id) {
-    return ByteSource.wrap(load(id));
+  @Nonnull
+  public WSLoaderResult<ByteSource> loadSource(String id) {
+    WSLoaderResult<byte[]> byteResult = load(id);
+    return new WSLoaderResult<ByteSource>(ByteSource.wrap(byteResult.get()), byteResult.isFromCache());
   }
 
-  public String loadString(String id) {
-    return new String(load(id), StandardCharsets.UTF_8);
+  @Nonnull
+  public WSLoaderResult<String> loadString(String id) {
+    WSLoaderResult<byte[]> byteResult = load(id);
+    return new WSLoaderResult<String>(new String(byteResult.get(), StandardCharsets.UTF_8), byteResult.isFromCache());
   }
 
   @Nonnull
-  public byte[] load(String id) {
+  public WSLoaderResult<byte[]> load(String id) {
     if (loadStrategy == CACHE_FIRST) {
       return loadFromCacheFirst(id);
     } else {
@@ -99,6 +107,7 @@ public boolean isCacheEnabled() {
   }
 
   private void switchToOffline() {
+    LOG.debug("server not available - switching to offline mode");
     serverStatus = NOT_ACCESSIBLE;
   }
 
@@ -110,71 +119,94 @@ private boolean isOffline() {
     return serverStatus == NOT_ACCESSIBLE;
   }
 
-  @Nonnull
-  private byte[] loadFromCacheFirst(String id) {
-    byte[] cached = loadFromCache(id);
-    if (cached != null) {
-      return cached;
+  private void updateCache(String id, byte[] value) {
+    if (cacheEnabled) {
+      try {
+        cache.put(client.getURI(id).toString(), value);
+      } catch (IOException e) {
+        LOG.warn("Error saving to WS cache", e);
+      }
     }
+  }
 
+  @Nonnull
+  private WSLoaderResult<byte[]> loadFromCacheFirst(String id) {
     try {
-      return loadFromServer(id);
-    } catch (Exception e) {
-      if (e.getCause() instanceof HttpDownloader.HttpException) {
-        throw e;
+      return loadFromCache(id);
+    } catch (NotAvailableException cacheNotAvailable) {
+      try {
+        return loadFromServer(id);
+      } catch (NotAvailableException serverNotAvailable) {
+        throw new IllegalStateException(FAIL_MSG, serverNotAvailable.getCause());
       }
-      throw new IllegalStateException(FAIL_MSG, e);
     }
   }
 
   @Nonnull
-  private byte[] loadFromServerFirst(String id) {
+  private WSLoaderResult<byte[]> loadFromServerFirst(String id) {
     try {
       return loadFromServer(id);
-    } catch (Exception serverException) {
-      if (serverException.getCause() instanceof HttpDownloader.HttpException) {
-        // http exceptions should always be thrown (no fallback)
-        throw serverException;
-      }
-      byte[] cached = loadFromCache(id);
-      if (cached != null) {
-        return cached;
+    } catch (NotAvailableException serverNotAvailable) {
+      try {
+        return loadFromCache(id);
+      } catch (NotAvailableException cacheNotAvailable) {
+        throw new IllegalStateException(FAIL_MSG, serverNotAvailable.getCause());
       }
-      throw new IllegalStateException(FAIL_MSG, serverException);
     }
   }
 
-  private byte[] loadFromCache(String id) {
+  @Nonnull
+  private WSLoaderResult<byte[]> loadFromCache(String id) throws NotAvailableException {
     if (!cacheEnabled) {
-      return null;
+      throw new NotAvailableException("cache disabled");
     }
 
     try {
-      return cache.get(client.getURI(id).toString(), null);
+      byte[] result = cache.get(client.getURI(id).toString(), null);
+      if (result == null) {
+        throw new NotAvailableException("resource not cached");
+      }
+      return new WSLoaderResult<byte[]>(result, true);
     } catch (IOException e) {
+      // any exception on the cache should fail fast
       throw new IllegalStateException(e);
     }
   }
 
-  private byte[] loadFromServer(String id) {
+  @Nonnull
+  private WSLoaderResult<byte[]> loadFromServer(String id) throws NotAvailableException {
     if (isOffline()) {
-      throw new IllegalStateException("Server is not accessible");
+      throw new NotAvailableException("Server not available");
     }
 
     try {
       InputStream is = client.load(id, REQUEST_METHOD, true, CONNECT_TIMEOUT, READ_TIMEOUT);
       switchToOnline();
       byte[] value = IOUtils.toByteArray(is);
-      if (cacheEnabled) {
-        cache.put(client.getURI(id).toString(), value);
-      }
-      return value;
+      updateCache(client.getURI(id).toString(), value);
+      return new WSLoaderResult<byte[]>(value, false);
     } catch (IllegalStateException e) {
+      if (e.getCause() instanceof HttpDownloader.HttpException) {
+        // fail fast if it could connect but there was a application-level error
+        throw e;
+      }
       switchToOffline();
-      throw e;
+      throw new NotAvailableException(e);
     } catch (Exception e) {
-      switchToOffline();
+      // fail fast
       throw new IllegalStateException(e);
     }
   }
+
+  private class NotAvailableException extends Exception {
+    private static final long serialVersionUID = 1L;
+
+    public NotAvailableException(String message) {
+      super(message);
+    }
+
+    public NotAvailableException(Throwable cause) {
+      super(cause);
+    }
+  }
 }

sonar-batch/src/main/java/org/sonar/batch/bootstrap/WSLoaderResult.java

@@ -0,0 +1,41 @@
+/*
+ * SonarQube, open source software quality management tool.
+ * Copyright (C) 2008-2014 SonarSource
+ * mailto:contact AT sonarsource DOT com
+ *
+ * SonarQube is free software; you can redistribute it and/or
+ * modify it under the terms of the GNU Lesser General Public
+ * License as published by the Free Software Foundation; either
+ * version 3 of the License, or (at your option) any later version.
+ *
+ * SonarQube is distributed in the hope that it will be useful,
+ * but WITHOUT ANY WARRANTY; without even the implied warranty of
+ * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
+ * Lesser General Public License for more details.
+ *
+ * You should have received a copy of the GNU Lesser General Public License
+ * along with this program; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA.
+ */
+package org.sonar.batch.bootstrap;
+
+import javax.annotation.Nonnull;
+
+public class WSLoaderResult<T> {
+  private T result;
+  private boolean fromCache;
+
+  public WSLoaderResult(T result, boolean fromCache) {
+    this.result = result;
+    this.fromCache = fromCache;
+  }
+
+  @Nonnull
+  public T get() {
+    return result;
+  }
+
+  public boolean isFromCache() {
+    return fromCache;
+  }
+}

sonar-batch/src/main/java/org/sonar/batch/issue/tracking/DefaultServerLineHashesLoader.java

@@ -19,8 +19,9 @@
  */
 package org.sonar.batch.issue.tracking;
 
-import org.sonar.batch.util.BatchUtils;
+import org.sonar.batch.bootstrap.WSLoaderResult;
 
+import org.sonar.batch.util.BatchUtils;
 import org.sonar.batch.bootstrap.WSLoader;
 import com.google.common.base.Splitter;
 import com.google.common.collect.Iterators;
@@ -45,10 +46,15 @@ private String loadHashesFromWs(String fileKey) {
     Profiler profiler = Profiler.createIfDebug(Loggers.get(getClass()))
       .addContext("file", fileKey)
       .startDebug("Load line hashes");
+    WSLoaderResult<String> result = wsLoader.loadString("/api/sources/hash?key=" + BatchUtils.encodeForUrl(fileKey));
     try {
-      return wsLoader.loadString("/api/sources/hash?key=" + BatchUtils.encodeForUrl(fileKey));
+      return result.get();
     } finally {
-      profiler.stopDebug();
+      if (result.isFromCache()) {
+        profiler.stopDebug();
+      } else {
+        profiler.stopDebug("Load line hashes (done from cache)");
+      }
     }
   }
 }