diff --git a/src/main/java/org/codelibs/fess/helper/IndexingHelper.java b/src/main/java/org/codelibs/fess/helper/IndexingHelper.java index 4d3e1d1d2..24a7f65e4 100644 --- a/src/main/java/org/codelibs/fess/helper/IndexingHelper.java +++ b/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 { diff --git a/src/main/java/org/codelibs/fess/indexer/IndexUpdater.java b/src/main/java/org/codelibs/fess/indexer/IndexUpdater.java index 84ef17f3c..fe67ebb37 100644 --- a/src/main/java/org/codelibs/fess/indexer/IndexUpdater.java +++ b/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 arList = getAccessResultList(cb); + List 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 accessResultList) { + private long cleanupAccessResults(final List 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 getAccessResultList(final Consumer cb) { + private List getAccessResultList(final Consumer 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) 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(); diff --git a/src/main/java/org/codelibs/fess/util/MemoryUtil.java b/src/main/java/org/codelibs/fess/util/MemoryUtil.java new file mode 100644 index 000000000..f97ae293a --- /dev/null +++ b/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); + } +}