fix #443 : add memory usage log

src/main/java/org/codelibs/fess/helper/IndexingHelper.java

@@ -24,6 +24,7 @@ import org.codelibs.fess.es.client.FessEsClient;
 import org.codelibs.fess.mylasta.direction.FessConfig;
 import org.codelibs.fess.util.ComponentUtil;
 import org.codelibs.fess.util.DocList;
+import org.codelibs.fess.util.MemoryUtil;
 import org.elasticsearch.action.count.CountResponse;
 import org.elasticsearch.index.query.QueryBuilder;
 import org.elasticsearch.index.query.QueryBuilders;
@@ -54,21 +55,13 @@ public class IndexingHelper {
                 fessEsClient.addAll(fessConfig.getIndexDocumentUpdateIndex(), fessConfig.getIndexDocumentType(), docList);
             }
             if (logger.isInfoEnabled()) {
-                final Runtime runtime = Runtime.getRuntime();
-                final long freeBytes = runtime.freeMemory();
-                final long maxBytes = runtime.maxMemory();
-                final long totalBytes = runtime.totalMemory();
-                final long usedBytes = totalBytes - freeBytes;
                 if (docList.getContentSize() > 0) {
                     logger.info("Sent " + docList.size() + " docs (Doc:{process " + docList.getProcessingTime() + "ms, send "
                             + (System.currentTimeMillis() - execTime) + "ms, size "
-                            + FileUtils.byteCountToDisplaySize(docList.getContentSize()) + "}, Mem:{used "
-                            + FileUtils.byteCountToDisplaySize(usedBytes) + ", heap " + FileUtils.byteCountToDisplaySize(totalBytes)
-                            + ", max " + FileUtils.byteCountToDisplaySize(maxBytes) + "})");
+                            + MemoryUtil.byteCountToDisplaySize(docList.getContentSize()) + "}, " + MemoryUtil.getMemoryUsageLog() + ")");
                 } else {
-                    logger.info("Sent " + docList.size() + " docs (Doc:{send " + (System.currentTimeMillis() - execTime)
-                            + "ms}, Mem:{used " + FileUtils.byteCountToDisplaySize(usedBytes) + ", heap "
-                            + FileUtils.byteCountToDisplaySize(totalBytes) + ", max " + FileUtils.byteCountToDisplaySize(maxBytes) + "})");
+                    logger.info("Sent " + docList.size() + " docs (Doc:{send " + (System.currentTimeMillis() - execTime) + "ms}, "
+                            + MemoryUtil.getMemoryUsageLog() + ")");
                 }
             }
         } finally {

src/main/java/org/codelibs/fess/indexer/IndexUpdater.java

@@ -49,6 +49,7 @@ import org.codelibs.fess.helper.SystemHelper;
 import org.codelibs.fess.mylasta.direction.FessConfig;
 import org.codelibs.fess.util.ComponentUtil;
 import org.codelibs.fess.util.DocList;
+import org.codelibs.fess.util.MemoryUtil;
 import org.elasticsearch.action.search.SearchRequestBuilder;
 import org.elasticsearch.index.query.QueryBuilder;
 import org.elasticsearch.index.query.QueryBuilders;
@@ -180,6 +181,7 @@ public class IndexUpdater extends Thread {
             long updateTime = System.currentTimeMillis();
             int errorCount = 0;
             int emptyListCount = 0;
+            long cleanupTime = -1;
             while (!finishCrawling || !accessResultList.isEmpty()) {
                 try {
                     final int sessionIdListSize = finishedSessionIdList.size();
@@ -208,7 +210,7 @@ public class IndexUpdater extends Thread {
 
                     updateTime = System.currentTimeMillis();
 
-                    List<EsAccessResult> arList = getAccessResultList(cb);
+                    List<EsAccessResult> arList = getAccessResultList(cb, cleanupTime);
                     if (arList.isEmpty()) {
                         emptyListCount++;
                     } else {
@@ -216,8 +218,8 @@ public class IndexUpdater extends Thread {
                     }
                     while (!arList.isEmpty()) {
                         processAccessResults(docList, accessResultList, arList);
-                        cleanupAccessResults(accessResultList);
-                        arList = getAccessResultList(cb);
+                        cleanupTime = cleanupAccessResults(accessResultList);
+                        arList = getAccessResultList(cb, cleanupTime);
                     }
                     if (!docList.isEmpty()) {
                         indexingHelper.sendDocuments(fessEsClient, docList);
@@ -353,7 +355,7 @@ public class IndexUpdater extends Thread {
                     final long processingTime = System.currentTimeMillis() - startTime;
                     docList.addProcessingTime(processingTime);
                     if (logger.isDebugEnabled()) {
-                        logger.debug("Added the document(" + FileUtils.byteCountToDisplaySize(docList.getContentSize()) + ", "
+                        logger.debug("Added the document(" + MemoryUtil.byteCountToDisplaySize(docList.getContentSize()) + ", "
                                 + processingTime + "ms). " + "The number of a document cache is " + docList.size() + ".");
                     }
 
@@ -452,21 +454,22 @@ public class IndexUpdater extends Thread {
         }
     }
 
-    private void cleanupAccessResults(final List<EsAccessResult> accessResultList) {
+    private long cleanupAccessResults(final List<EsAccessResult> accessResultList) {
         if (!accessResultList.isEmpty()) {
             final long execTime = System.currentTimeMillis();
             final int size = accessResultList.size();
             dataService.update(accessResultList);
             accessResultList.clear();
+            final long time = System.currentTimeMillis() - execTime;
             if (logger.isDebugEnabled()) {
-                logger.debug("Updated " + size + " access results. The execution time is " + (System.currentTimeMillis() - execTime)
-                        + "ms.");
+                logger.debug("Updated " + size + " access results. The execution time is " + time + "ms.");
             }
+            return time;
         }
-
+        return -1;
     }
 
-    private List<EsAccessResult> getAccessResultList(final Consumer<SearchRequestBuilder> cb) {
+    private List<EsAccessResult> getAccessResultList(final Consumer<SearchRequestBuilder> cb, final long cleanupTime) {
         if (logger.isDebugEnabled()) {
             logger.debug("Getting documents in IndexUpdater queue.");
         }
@@ -483,11 +486,21 @@ public class IndexUpdater extends Thread {
         }
         final long totalHits = ((EsResultList<EsAccessResult>) arList).getTotalHits();
         if (logger.isInfoEnabled()) {
+            final StringBuilder buf = new StringBuilder(100);
+            buf.append("Processing ");
             if (totalHits > 0) {
-                logger.info("Processing " + arList.size() + "/" + totalHits + " docs (" + (System.currentTimeMillis() - execTime) + "ms)");
+                buf.append(arList.size()).append('/').append(totalHits).append(" docs (Doc:{access ");
             } else {
-                logger.info("Processing no docs (" + (System.currentTimeMillis() - execTime) + "ms)");
+                buf.append("no docs (Doc:{access ");
+            }
+            buf.append(System.currentTimeMillis() - execTime).append("ms");
+            if (cleanupTime >= 0) {
+                buf.append(", cleanup ").append(cleanupTime).append("ms");
             }
+            buf.append("}, ");
+            buf.append(MemoryUtil.getMemoryUsageLog());
+            buf.append(')');
+            logger.info(buf.toString());
         }
         final long unprocessedDocumentSize = fessConfig.getIndexerUnprocessedDocumentSizeAsInteger().longValue();
         final IntervalControlHelper intervalControlHelper = ComponentUtil.getIntervalControlHelper();

src/main/java/org/codelibs/fess/util/MemoryUtil.java

@@ -0,0 +1,38 @@
+/*
+ * Copyright 2012-2016 CodeLibs Project and the Others.
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *     http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND,
+ * either express or implied. See the License for the specific language
+ * governing permissions and limitations under the License.
+ */
+package org.codelibs.fess.util;
+
+import org.apache.commons.io.FileUtils;
+import org.codelibs.core.lang.StringUtil;
+
+public final class MemoryUtil {
+    private MemoryUtil() {
+    }
+
+    public static String getMemoryUsageLog() {
+        final Runtime runtime = Runtime.getRuntime();
+        final long freeBytes = runtime.freeMemory();
+        final long maxBytes = runtime.maxMemory();
+        final long totalBytes = runtime.totalMemory();
+        final long usedBytes = totalBytes - freeBytes;
+        return "Mem:{used " + byteCountToDisplaySize(usedBytes) + ", heap " + byteCountToDisplaySize(totalBytes) + ", max "
+                + byteCountToDisplaySize(maxBytes) + "}";
+    }
+
+    public static String byteCountToDisplaySize(long size) {
+        return FileUtils.byteCountToDisplaySize(size).replace(" ", StringUtil.EMPTY);
+    }
+}