From c697e822d25a706da87c104a838100190caf37be Mon Sep 17 00:00:00 2001 From: Vladimir Kotal Date: Thu, 19 Jul 2018 17:48:13 +0200 Subject: [PATCH 1/5] add elapsed statistics logs to suggester rebuild --- .../java/org/opengrok/suggest/Suggester.java | 11 ++- .../org/opengrok/suggest/util/Statistics.java | 42 +++++++++++ .../opengrok/suggest/util/StringUtils.java | 74 +++++++++++++++++++ 3 files changed, 123 insertions(+), 4 deletions(-) create mode 100644 suggester/src/main/java/org/opengrok/suggest/util/Statistics.java create mode 100644 suggester/src/main/java/org/opengrok/suggest/util/StringUtils.java diff --git a/suggester/src/main/java/org/opengrok/suggest/Suggester.java b/suggester/src/main/java/org/opengrok/suggest/Suggester.java index 3ed2c93ca8b..007e2bf9cbf 100644 --- a/suggester/src/main/java/org/opengrok/suggest/Suggester.java +++ b/suggester/src/main/java/org/opengrok/suggest/Suggester.java @@ -31,6 +31,7 @@ import org.apache.lucene.util.BytesRef; import org.opengrok.suggest.query.SuggesterPrefixQuery; import org.opengrok.suggest.query.SuggesterQuery; +import org.opengrok.suggest.util.Statistics; import java.io.Closeable; import java.io.File; @@ -148,6 +149,7 @@ public void init(final Collection luceneIndexes) { } synchronized (lock) { + Statistics elapsed = new Statistics(); logger.log(Level.INFO, "Initializing suggester"); ExecutorService executor = Executors.newWorkStealingPool(rebuildParallelismLevel); @@ -156,7 +158,7 @@ public void init(final Collection luceneIndexes) { submitInitIfIndexExists(executor, indexDir); } - shutdownAndAwaitTermination(executor, "Suggester successfully initialized"); + shutdownAndAwaitTermination(executor, elapsed, "Suggester successfully initialized"); } } @@ -209,11 +211,11 @@ private boolean indexExists(final Path indexDir) throws IOException { } } - private void shutdownAndAwaitTermination(final ExecutorService executorService, final String logMessageOnSuccess) { + private void shutdownAndAwaitTermination(final ExecutorService executorService, Statistics elapsed, final String logMessageOnSuccess) { executorService.shutdown(); try { executorService.awaitTermination(awaitTerminationTime.toMillis(), TimeUnit.MILLISECONDS); - logger.log(Level.INFO, logMessageOnSuccess); + elapsed.report(logger, logMessageOnSuccess); } catch (InterruptedException e) { logger.log(Level.SEVERE, "Interrupted while building suggesters", e); Thread.currentThread().interrupt(); @@ -231,6 +233,7 @@ public void rebuild(final Collection indexDirs) { } synchronized (lock) { + Statistics elapsed = new Statistics(); logger.log(Level.INFO, "Rebuilding the following suggesters: {0}", indexDirs); ExecutorService executor = Executors.newWorkStealingPool(rebuildParallelismLevel); @@ -244,7 +247,7 @@ public void rebuild(final Collection indexDirs) { } } - shutdownAndAwaitTermination(executor, "Suggesters for " + indexDirs + " were successfully rebuilt"); + shutdownAndAwaitTermination(executor, elapsed, "Suggesters for " + indexDirs + " were successfully rebuilt"); } } diff --git a/suggester/src/main/java/org/opengrok/suggest/util/Statistics.java b/suggester/src/main/java/org/opengrok/suggest/util/Statistics.java new file mode 100644 index 00000000000..39ed55cde24 --- /dev/null +++ b/suggester/src/main/java/org/opengrok/suggest/util/Statistics.java @@ -0,0 +1,42 @@ +/* + * CDDL HEADER START + * + * The contents of this file are subject to the terms of the + * Common Development and Distribution License (the "License"). + * You may not use this file except in compliance with the License. + * + * See LICENSE.txt included in this distribution for the specific + * language governing permissions and limitations under the License. + * + * When distributing Covered Code, include this CDDL HEADER in each + * file and include the License file at LICENSE.txt. + * If applicable, add the following below this CDDL HEADER, with the + * fields enclosed by brackets "[]" replaced with your own identifying + * information: Portions Copyright [yyyy] [name of copyright owner] + * + * CDDL HEADER END + */ + +/* + * Copyright (c) 2014, 2018, Oracle and/or its affiliates. All rights reserved. + */ + +package org.opengrok.suggest.util; + +import java.util.logging.Level; +import java.util.logging.Logger; + +public class Statistics { + + private final long startTime; + + public Statistics() { + startTime = System.currentTimeMillis(); + } + + public void report(Logger log, String msg) { + long stopTime = System.currentTimeMillis(); + String time_str = StringUtils.getReadableTime(stopTime - startTime); + log.log(Level.INFO, msg + " (took {0})", time_str); + } +} diff --git a/suggester/src/main/java/org/opengrok/suggest/util/StringUtils.java b/suggester/src/main/java/org/opengrok/suggest/util/StringUtils.java new file mode 100644 index 00000000000..7071640e079 --- /dev/null +++ b/suggester/src/main/java/org/opengrok/suggest/util/StringUtils.java @@ -0,0 +1,74 @@ +/* + * CDDL HEADER START + * + * The contents of this file are subject to the terms of the + * Common Development and Distribution License (the "License"). + * You may not use this file except in compliance with the License. + * + * See LICENSE.txt included in this distribution for the specific + * language governing permissions and limitations under the License. + * + * When distributing Covered Code, include this CDDL HEADER in each + * file and include the License file at LICENSE.txt. + * If applicable, add the following below this CDDL HEADER, with the + * fields enclosed by brackets "[]" replaced with your own identifying + * information: Portions Copyright [yyyy] [name of copyright owner] + * + * CDDL HEADER END + */ + +/* + * Copyright (c) 2008, 2018, Oracle and/or its affiliates. All rights reserved. + * Portions Copyright (c) 2017-2018, Chris Fraire . + */ + +package org.opengrok.suggest.util; + +/** + * Various String utility methods taken from + * org.opensolaris.opengrok.util.StringUtils + * + * @author austvik + */ +public final class StringUtils { + + /** + * Convert value in milliseconds to readable time. + * @param time_ms delta in milliseconds + * @return human readable string + */ + public static String getReadableTime(long time_ms) { + String output = ""; + long time_delta = time_ms; + + int milliseconds = (int) (time_delta % 1000); + time_delta /= 1000; + int seconds = (int) (time_delta % 60); + time_delta /= 60; + int minutes = (int) (time_delta % 60); + time_delta /= 60; + int hours = (int) (time_delta % 24); + int days = (int) (time_delta / 24); + + if (days != 0) { + output += String.format("%d day", days); + if (days > 1) { + output += "s"; + } + if ((hours != 0) || (minutes != 0) || (seconds != 0)) { + output += " "; + } + } + if ((hours != 0) || (minutes != 0)) { + return output + String.format("%d:%02d:%02d", hours, minutes, seconds); + } + if (seconds != 0) { + return output + String.format("%d.%d seconds", seconds, milliseconds); + } + if (milliseconds != 0) { + return output + String.format("%d ms", milliseconds); + } + + return (output.length() == 0 ? "0" : output); + } +} From 6eb5ecf99d3fa3312ad417d0abae66a2a892c49d Mon Sep 17 00:00:00 2001 From: Vladimir Kotal Date: Tue, 13 Aug 2019 13:35:11 +0200 Subject: [PATCH 2/5] use simpler statistics --- .../java/org/opengrok/suggest/Suggester.java | 64 ++++++++-------- .../org/opengrok/suggest/util/Statistics.java | 42 ----------- .../opengrok/suggest/util/StringUtils.java | 74 ------------------- 3 files changed, 33 insertions(+), 147 deletions(-) delete mode 100644 suggester/src/main/java/org/opengrok/suggest/util/Statistics.java delete mode 100644 suggester/src/main/java/org/opengrok/suggest/util/StringUtils.java diff --git a/suggester/src/main/java/org/opengrok/suggest/Suggester.java b/suggester/src/main/java/org/opengrok/suggest/Suggester.java index 007e2bf9cbf..7bda3d76bb4 100644 --- a/suggester/src/main/java/org/opengrok/suggest/Suggester.java +++ b/suggester/src/main/java/org/opengrok/suggest/Suggester.java @@ -22,6 +22,7 @@ */ package org.opengrok.suggest; +import org.apache.commons.lang3.time.DurationFormatUtils; import org.apache.lucene.index.DirectoryReader; import org.apache.lucene.index.IndexReader; import org.apache.lucene.index.Term; @@ -31,7 +32,6 @@ import org.apache.lucene.util.BytesRef; import org.opengrok.suggest.query.SuggesterPrefixQuery; import org.opengrok.suggest.query.SuggesterQuery; -import org.opengrok.suggest.util.Statistics; import java.io.Closeable; import java.io.File; @@ -65,7 +65,7 @@ public final class Suggester implements Closeable { private static final String PROJECTS_DISABLED_KEY = ""; - private static final Logger logger = Logger.getLogger(Suggester.class.getName()); + private static final Logger LOGGER = Logger.getLogger(Suggester.class.getName()); private final Map projectData = new ConcurrentHashMap<>(); @@ -141,7 +141,7 @@ public Suggester( */ public void init(final Collection luceneIndexes) { if (luceneIndexes == null || luceneIndexes.isEmpty()) { - logger.log(Level.INFO, "No index directories found, exiting..."); + LOGGER.log(Level.INFO, "No index directories found, exiting..."); return; } if (!projectsEnabled && luceneIndexes.size() > 1) { @@ -149,8 +149,8 @@ public void init(final Collection luceneIndexes) { } synchronized (lock) { - Statistics elapsed = new Statistics(); - logger.log(Level.INFO, "Initializing suggester"); + long startTime = System.currentTimeMillis(); + LOGGER.log(Level.INFO, "Initializing suggester"); ExecutorService executor = Executors.newWorkStealingPool(rebuildParallelismLevel); @@ -158,7 +158,7 @@ public void init(final Collection luceneIndexes) { submitInitIfIndexExists(executor, indexDir); } - shutdownAndAwaitTermination(executor, elapsed, "Suggester successfully initialized"); + shutdownAndAwaitTermination(executor, startTime, "Suggester successfully initialized"); } } @@ -167,10 +167,10 @@ private void submitInitIfIndexExists(final ExecutorService executorService, fina if (indexExists(indexDir.path)) { executorService.submit(getInitRunnable(indexDir)); } else { - logger.log(Level.FINE, "Index in {0} directory does not exist, skipping...", indexDir); + LOGGER.log(Level.FINE, "Index in {0} directory does not exist, skipping...", indexDir); } } catch (IOException e) { - logger.log(Level.WARNING, "Could not check if index exists", e); + LOGGER.log(Level.WARNING, "Could not check if index exists", e); } } @@ -178,7 +178,7 @@ private Runnable getInitRunnable(final NamedIndexDir indexDir) { return () -> { try { Instant start = Instant.now(); - logger.log(Level.FINE, "Initializing {0}", indexDir); + LOGGER.log(Level.FINE, "Initializing {0}", indexDir); SuggesterProjectData wfst = new SuggesterProjectData(FSDirectory.open(indexDir.path), getSuggesterDir(indexDir.name), allowMostPopular, allowedFields); @@ -190,9 +190,9 @@ private Runnable getInitRunnable(final NamedIndexDir indexDir) { } Duration d = Duration.between(start, Instant.now()); - logger.log(Level.FINE, "Finished initialization of {0}, took {1}", new Object[] {indexDir, d}); + LOGGER.log(Level.FINE, "Finished initialization of {0}, took {1}", new Object[] {indexDir, d}); } catch (Exception e) { - logger.log(Level.SEVERE, "Could not initialize suggester data for " + indexDir, e); + LOGGER.log(Level.SEVERE, "Could not initialize suggester data for " + indexDir, e); } }; } @@ -211,13 +211,15 @@ private boolean indexExists(final Path indexDir) throws IOException { } } - private void shutdownAndAwaitTermination(final ExecutorService executorService, Statistics elapsed, final String logMessageOnSuccess) { + private void shutdownAndAwaitTermination(final ExecutorService executorService, long startTime, final String logMessageOnSuccess) { executorService.shutdown(); try { executorService.awaitTermination(awaitTerminationTime.toMillis(), TimeUnit.MILLISECONDS); - elapsed.report(logger, logMessageOnSuccess); + LOGGER.log(Level.INFO, logMessageOnSuccess + " (took {0})", + DurationFormatUtils.formatDurationWords(System.currentTimeMillis() - startTime, + true, true)); } catch (InterruptedException e) { - logger.log(Level.SEVERE, "Interrupted while building suggesters", e); + LOGGER.log(Level.SEVERE, "Interrupted while building suggesters", e); Thread.currentThread().interrupt(); } } @@ -228,13 +230,13 @@ private void shutdownAndAwaitTermination(final ExecutorService executorService, */ public void rebuild(final Collection indexDirs) { if (indexDirs == null || indexDirs.isEmpty()) { - logger.log(Level.INFO, "Not rebuilding suggester data because no index directories were specified"); + LOGGER.log(Level.INFO, "Not rebuilding suggester data because no index directories were specified"); return; } synchronized (lock) { - Statistics elapsed = new Statistics(); - logger.log(Level.INFO, "Rebuilding the following suggesters: {0}", indexDirs); + long startTime = System.currentTimeMillis(); + LOGGER.log(Level.INFO, "Rebuilding the following suggesters: {0}", indexDirs); ExecutorService executor = Executors.newWorkStealingPool(rebuildParallelismLevel); @@ -247,7 +249,7 @@ public void rebuild(final Collection indexDirs) { } } - shutdownAndAwaitTermination(executor, elapsed, "Suggesters for " + indexDirs + " were successfully rebuilt"); + shutdownAndAwaitTermination(executor, startTime, "Suggesters for " + indexDirs + " were successfully rebuilt"); } } @@ -255,13 +257,13 @@ private Runnable getRebuildRunnable(final SuggesterProjectData data) { return () -> { try { Instant start = Instant.now(); - logger.log(Level.FINE, "Rebuilding {0}", data); + LOGGER.log(Level.FINE, "Rebuilding {0}", data); data.rebuild(); Duration d = Duration.between(start, Instant.now()); - logger.log(Level.FINE, "Rebuild of {0} finished, took {1}", new Object[] {data, d}); + LOGGER.log(Level.FINE, "Rebuild of {0} finished, took {1}", new Object[] {data, d}); } catch (Exception e) { - logger.log(Level.SEVERE, "Could not rebuild suggester", e); + LOGGER.log(Level.SEVERE, "Could not rebuild suggester", e); } }; } @@ -276,12 +278,12 @@ public void remove(final Iterable names) { } synchronized (lock) { - logger.log(Level.INFO, "Removing following suggesters: {0}", names); + LOGGER.log(Level.INFO, "Removing following suggesters: {0}", names); for (String suggesterName : names) { SuggesterProjectData collection = projectData.get(suggesterName); if (collection == null) { - logger.log(Level.WARNING, "Unknown suggester {0}", suggesterName); + LOGGER.log(Level.WARNING, "Unknown suggester {0}", suggesterName); continue; } collection.remove(); @@ -332,7 +334,7 @@ private Suggestions prefixLookup( List results = readers.parallelStream().flatMap(namedIndexReader -> { SuggesterProjectData data = projectData.get(namedIndexReader.name); if (data == null) { - logger.log(Level.FINE, "{0} not yet initialized", namedIndexReader.name); + LOGGER.log(Level.FINE, "{0} not yet initialized", namedIndexReader.name); partialResult.value = true; return Stream.empty(); } @@ -371,7 +373,7 @@ private Suggestions complexLookup( try { futures = executorService.invokeAll(searchTasks, timeThreshold, TimeUnit.MILLISECONDS); } catch (InterruptedException e) { - logger.log(Level.WARNING, "Interrupted while invoking suggester search", e); + LOGGER.log(Level.WARNING, "Interrupted while invoking suggester search", e); Thread.currentThread().interrupt(); return new Suggestions(Collections.emptyList(), true); } @@ -390,7 +392,7 @@ private Suggestions complexLookup( try { searchTask.wait(); } catch (InterruptedException e) { - logger.log(Level.WARNING, "Interrupted while waiting for task: {0}", searchTask); + LOGGER.log(Level.WARNING, "Interrupted while waiting for task: {0}", searchTask); Thread.currentThread().interrupt(); } } @@ -430,7 +432,7 @@ public void onSearch(final Iterable projects, final Query query) { } } } catch (Exception e) { - logger.log(Level.FINE, "Could not update search count map", e); + LOGGER.log(Level.FINE, "Could not update search count map", e); } } @@ -476,7 +478,7 @@ public void increaseSearchCount(final String project, final Term term, final int } if (data == null) { - logger.log(Level.WARNING, "Cannot update search count because of missing suggester data{}", + LOGGER.log(Level.WARNING, "Cannot update search count because of missing suggester data{}", projectsEnabled ? " for project " + project : ""); return; } @@ -500,7 +502,7 @@ public List> getSearchCounts( ) { SuggesterProjectData data = projectData.get(project); if (data == null) { - logger.log(Level.FINE, "Cannot retrieve search counts because suggester data for project {0} was not found", + LOGGER.log(Level.FINE, "Cannot retrieve search counts because suggester data for project {0} was not found", project); return Collections.emptyList(); } @@ -518,7 +520,7 @@ public void close() { try { f.close(); } catch (IOException e) { - logger.log(Level.WARNING, "Could not close suggester data " + f, e); + LOGGER.log(Level.WARNING, "Could not close suggester data " + f, e); } }); } @@ -552,7 +554,7 @@ public Void call() { SuggesterProjectData data = projectData.get(namedIndexReader.name); if (data == null) { - logger.log(Level.FINE, "{0} not yet initialized", namedIndexReader.name); + LOGGER.log(Level.FINE, "{0} not yet initialized", namedIndexReader.name); return null; } boolean gotLock = data.tryLock(); diff --git a/suggester/src/main/java/org/opengrok/suggest/util/Statistics.java b/suggester/src/main/java/org/opengrok/suggest/util/Statistics.java deleted file mode 100644 index 39ed55cde24..00000000000 --- a/suggester/src/main/java/org/opengrok/suggest/util/Statistics.java +++ /dev/null @@ -1,42 +0,0 @@ -/* - * CDDL HEADER START - * - * The contents of this file are subject to the terms of the - * Common Development and Distribution License (the "License"). - * You may not use this file except in compliance with the License. - * - * See LICENSE.txt included in this distribution for the specific - * language governing permissions and limitations under the License. - * - * When distributing Covered Code, include this CDDL HEADER in each - * file and include the License file at LICENSE.txt. - * If applicable, add the following below this CDDL HEADER, with the - * fields enclosed by brackets "[]" replaced with your own identifying - * information: Portions Copyright [yyyy] [name of copyright owner] - * - * CDDL HEADER END - */ - -/* - * Copyright (c) 2014, 2018, Oracle and/or its affiliates. All rights reserved. - */ - -package org.opengrok.suggest.util; - -import java.util.logging.Level; -import java.util.logging.Logger; - -public class Statistics { - - private final long startTime; - - public Statistics() { - startTime = System.currentTimeMillis(); - } - - public void report(Logger log, String msg) { - long stopTime = System.currentTimeMillis(); - String time_str = StringUtils.getReadableTime(stopTime - startTime); - log.log(Level.INFO, msg + " (took {0})", time_str); - } -} diff --git a/suggester/src/main/java/org/opengrok/suggest/util/StringUtils.java b/suggester/src/main/java/org/opengrok/suggest/util/StringUtils.java deleted file mode 100644 index 7071640e079..00000000000 --- a/suggester/src/main/java/org/opengrok/suggest/util/StringUtils.java +++ /dev/null @@ -1,74 +0,0 @@ -/* - * CDDL HEADER START - * - * The contents of this file are subject to the terms of the - * Common Development and Distribution License (the "License"). - * You may not use this file except in compliance with the License. - * - * See LICENSE.txt included in this distribution for the specific - * language governing permissions and limitations under the License. - * - * When distributing Covered Code, include this CDDL HEADER in each - * file and include the License file at LICENSE.txt. - * If applicable, add the following below this CDDL HEADER, with the - * fields enclosed by brackets "[]" replaced with your own identifying - * information: Portions Copyright [yyyy] [name of copyright owner] - * - * CDDL HEADER END - */ - -/* - * Copyright (c) 2008, 2018, Oracle and/or its affiliates. All rights reserved. - * Portions Copyright (c) 2017-2018, Chris Fraire . - */ - -package org.opengrok.suggest.util; - -/** - * Various String utility methods taken from - * org.opensolaris.opengrok.util.StringUtils - * - * @author austvik - */ -public final class StringUtils { - - /** - * Convert value in milliseconds to readable time. - * @param time_ms delta in milliseconds - * @return human readable string - */ - public static String getReadableTime(long time_ms) { - String output = ""; - long time_delta = time_ms; - - int milliseconds = (int) (time_delta % 1000); - time_delta /= 1000; - int seconds = (int) (time_delta % 60); - time_delta /= 60; - int minutes = (int) (time_delta % 60); - time_delta /= 60; - int hours = (int) (time_delta % 24); - int days = (int) (time_delta / 24); - - if (days != 0) { - output += String.format("%d day", days); - if (days > 1) { - output += "s"; - } - if ((hours != 0) || (minutes != 0) || (seconds != 0)) { - output += " "; - } - } - if ((hours != 0) || (minutes != 0)) { - return output + String.format("%d:%02d:%02d", hours, minutes, seconds); - } - if (seconds != 0) { - return output + String.format("%d.%d seconds", seconds, milliseconds); - } - if (milliseconds != 0) { - return output + String.format("%d ms", milliseconds); - } - - return (output.length() == 0 ? "0" : output); - } -} From 2a93d1109d9d29623b8d1c98ba468d99bb6857c3 Mon Sep 17 00:00:00 2001 From: Vladimir Kotal Date: Tue, 13 Aug 2019 14:04:23 +0200 Subject: [PATCH 3/5] logger --- .../java/org/opengrok/suggest/Suggester.java | 50 +++++++++---------- 1 file changed, 25 insertions(+), 25 deletions(-) diff --git a/suggester/src/main/java/org/opengrok/suggest/Suggester.java b/suggester/src/main/java/org/opengrok/suggest/Suggester.java index 7bda3d76bb4..675a10df580 100644 --- a/suggester/src/main/java/org/opengrok/suggest/Suggester.java +++ b/suggester/src/main/java/org/opengrok/suggest/Suggester.java @@ -65,7 +65,7 @@ public final class Suggester implements Closeable { private static final String PROJECTS_DISABLED_KEY = ""; - private static final Logger LOGGER = Logger.getLogger(Suggester.class.getName()); + private static final Logger logger = Logger.getLogger(Suggester.class.getName()); private final Map projectData = new ConcurrentHashMap<>(); @@ -141,7 +141,7 @@ public Suggester( */ public void init(final Collection luceneIndexes) { if (luceneIndexes == null || luceneIndexes.isEmpty()) { - LOGGER.log(Level.INFO, "No index directories found, exiting..."); + logger.log(Level.INFO, "No index directories found, exiting..."); return; } if (!projectsEnabled && luceneIndexes.size() > 1) { @@ -150,7 +150,7 @@ public void init(final Collection luceneIndexes) { synchronized (lock) { long startTime = System.currentTimeMillis(); - LOGGER.log(Level.INFO, "Initializing suggester"); + logger.log(Level.INFO, "Initializing suggester"); ExecutorService executor = Executors.newWorkStealingPool(rebuildParallelismLevel); @@ -167,10 +167,10 @@ private void submitInitIfIndexExists(final ExecutorService executorService, fina if (indexExists(indexDir.path)) { executorService.submit(getInitRunnable(indexDir)); } else { - LOGGER.log(Level.FINE, "Index in {0} directory does not exist, skipping...", indexDir); + logger.log(Level.FINE, "Index in {0} directory does not exist, skipping...", indexDir); } } catch (IOException e) { - LOGGER.log(Level.WARNING, "Could not check if index exists", e); + logger.log(Level.WARNING, "Could not check if index exists", e); } } @@ -178,7 +178,7 @@ private Runnable getInitRunnable(final NamedIndexDir indexDir) { return () -> { try { Instant start = Instant.now(); - LOGGER.log(Level.FINE, "Initializing {0}", indexDir); + logger.log(Level.FINE, "Initializing {0}", indexDir); SuggesterProjectData wfst = new SuggesterProjectData(FSDirectory.open(indexDir.path), getSuggesterDir(indexDir.name), allowMostPopular, allowedFields); @@ -190,9 +190,9 @@ private Runnable getInitRunnable(final NamedIndexDir indexDir) { } Duration d = Duration.between(start, Instant.now()); - LOGGER.log(Level.FINE, "Finished initialization of {0}, took {1}", new Object[] {indexDir, d}); + logger.log(Level.FINE, "Finished initialization of {0}, took {1}", new Object[] {indexDir, d}); } catch (Exception e) { - LOGGER.log(Level.SEVERE, "Could not initialize suggester data for " + indexDir, e); + logger.log(Level.SEVERE, "Could not initialize suggester data for " + indexDir, e); } }; } @@ -215,11 +215,11 @@ private void shutdownAndAwaitTermination(final ExecutorService executorService, executorService.shutdown(); try { executorService.awaitTermination(awaitTerminationTime.toMillis(), TimeUnit.MILLISECONDS); - LOGGER.log(Level.INFO, logMessageOnSuccess + " (took {0})", + logger.log(Level.INFO, logMessageOnSuccess + " (took {0})", DurationFormatUtils.formatDurationWords(System.currentTimeMillis() - startTime, true, true)); } catch (InterruptedException e) { - LOGGER.log(Level.SEVERE, "Interrupted while building suggesters", e); + logger.log(Level.SEVERE, "Interrupted while building suggesters", e); Thread.currentThread().interrupt(); } } @@ -230,13 +230,13 @@ private void shutdownAndAwaitTermination(final ExecutorService executorService, */ public void rebuild(final Collection indexDirs) { if (indexDirs == null || indexDirs.isEmpty()) { - LOGGER.log(Level.INFO, "Not rebuilding suggester data because no index directories were specified"); + logger.log(Level.INFO, "Not rebuilding suggester data because no index directories were specified"); return; } synchronized (lock) { long startTime = System.currentTimeMillis(); - LOGGER.log(Level.INFO, "Rebuilding the following suggesters: {0}", indexDirs); + logger.log(Level.INFO, "Rebuilding the following suggesters: {0}", indexDirs); ExecutorService executor = Executors.newWorkStealingPool(rebuildParallelismLevel); @@ -257,13 +257,13 @@ private Runnable getRebuildRunnable(final SuggesterProjectData data) { return () -> { try { Instant start = Instant.now(); - LOGGER.log(Level.FINE, "Rebuilding {0}", data); + logger.log(Level.FINE, "Rebuilding {0}", data); data.rebuild(); Duration d = Duration.between(start, Instant.now()); - LOGGER.log(Level.FINE, "Rebuild of {0} finished, took {1}", new Object[] {data, d}); + logger.log(Level.FINE, "Rebuild of {0} finished, took {1}", new Object[] {data, d}); } catch (Exception e) { - LOGGER.log(Level.SEVERE, "Could not rebuild suggester", e); + logger.log(Level.SEVERE, "Could not rebuild suggester", e); } }; } @@ -278,12 +278,12 @@ public void remove(final Iterable names) { } synchronized (lock) { - LOGGER.log(Level.INFO, "Removing following suggesters: {0}", names); + logger.log(Level.INFO, "Removing following suggesters: {0}", names); for (String suggesterName : names) { SuggesterProjectData collection = projectData.get(suggesterName); if (collection == null) { - LOGGER.log(Level.WARNING, "Unknown suggester {0}", suggesterName); + logger.log(Level.WARNING, "Unknown suggester {0}", suggesterName); continue; } collection.remove(); @@ -334,7 +334,7 @@ private Suggestions prefixLookup( List results = readers.parallelStream().flatMap(namedIndexReader -> { SuggesterProjectData data = projectData.get(namedIndexReader.name); if (data == null) { - LOGGER.log(Level.FINE, "{0} not yet initialized", namedIndexReader.name); + logger.log(Level.FINE, "{0} not yet initialized", namedIndexReader.name); partialResult.value = true; return Stream.empty(); } @@ -373,7 +373,7 @@ private Suggestions complexLookup( try { futures = executorService.invokeAll(searchTasks, timeThreshold, TimeUnit.MILLISECONDS); } catch (InterruptedException e) { - LOGGER.log(Level.WARNING, "Interrupted while invoking suggester search", e); + logger.log(Level.WARNING, "Interrupted while invoking suggester search", e); Thread.currentThread().interrupt(); return new Suggestions(Collections.emptyList(), true); } @@ -392,7 +392,7 @@ private Suggestions complexLookup( try { searchTask.wait(); } catch (InterruptedException e) { - LOGGER.log(Level.WARNING, "Interrupted while waiting for task: {0}", searchTask); + logger.log(Level.WARNING, "Interrupted while waiting for task: {0}", searchTask); Thread.currentThread().interrupt(); } } @@ -432,7 +432,7 @@ public void onSearch(final Iterable projects, final Query query) { } } } catch (Exception e) { - LOGGER.log(Level.FINE, "Could not update search count map", e); + logger.log(Level.FINE, "Could not update search count map", e); } } @@ -478,7 +478,7 @@ public void increaseSearchCount(final String project, final Term term, final int } if (data == null) { - LOGGER.log(Level.WARNING, "Cannot update search count because of missing suggester data{}", + logger.log(Level.WARNING, "Cannot update search count because of missing suggester data{}", projectsEnabled ? " for project " + project : ""); return; } @@ -502,7 +502,7 @@ public List> getSearchCounts( ) { SuggesterProjectData data = projectData.get(project); if (data == null) { - LOGGER.log(Level.FINE, "Cannot retrieve search counts because suggester data for project {0} was not found", + logger.log(Level.FINE, "Cannot retrieve search counts because suggester data for project {0} was not found", project); return Collections.emptyList(); } @@ -520,7 +520,7 @@ public void close() { try { f.close(); } catch (IOException e) { - LOGGER.log(Level.WARNING, "Could not close suggester data " + f, e); + logger.log(Level.WARNING, "Could not close suggester data " + f, e); } }); } @@ -554,7 +554,7 @@ public Void call() { SuggesterProjectData data = projectData.get(namedIndexReader.name); if (data == null) { - LOGGER.log(Level.FINE, "{0} not yet initialized", namedIndexReader.name); + logger.log(Level.FINE, "{0} not yet initialized", namedIndexReader.name); return null; } boolean gotLock = data.tryLock(); From 86f7528eac9d8299d89d73c5f4da44cf008d9136 Mon Sep 17 00:00:00 2001 From: Vladimir Kotal Date: Tue, 13 Aug 2019 14:52:36 +0200 Subject: [PATCH 4/5] use Instant/Duration --- .../main/java/org/opengrok/suggest/Suggester.java | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/suggester/src/main/java/org/opengrok/suggest/Suggester.java b/suggester/src/main/java/org/opengrok/suggest/Suggester.java index 675a10df580..ceae9017065 100644 --- a/suggester/src/main/java/org/opengrok/suggest/Suggester.java +++ b/suggester/src/main/java/org/opengrok/suggest/Suggester.java @@ -149,7 +149,7 @@ public void init(final Collection luceneIndexes) { } synchronized (lock) { - long startTime = System.currentTimeMillis(); + Instant start = Instant.now(); logger.log(Level.INFO, "Initializing suggester"); ExecutorService executor = Executors.newWorkStealingPool(rebuildParallelismLevel); @@ -158,7 +158,7 @@ public void init(final Collection luceneIndexes) { submitInitIfIndexExists(executor, indexDir); } - shutdownAndAwaitTermination(executor, startTime, "Suggester successfully initialized"); + shutdownAndAwaitTermination(executor, start, "Suggester successfully initialized"); } } @@ -211,12 +211,12 @@ private boolean indexExists(final Path indexDir) throws IOException { } } - private void shutdownAndAwaitTermination(final ExecutorService executorService, long startTime, final String logMessageOnSuccess) { + private void shutdownAndAwaitTermination(final ExecutorService executorService, Instant start, final String logMessageOnSuccess) { executorService.shutdown(); try { executorService.awaitTermination(awaitTerminationTime.toMillis(), TimeUnit.MILLISECONDS); logger.log(Level.INFO, logMessageOnSuccess + " (took {0})", - DurationFormatUtils.formatDurationWords(System.currentTimeMillis() - startTime, + DurationFormatUtils.formatDurationWords(Duration.between(start, Instant.now()).toMillis(), true, true)); } catch (InterruptedException e) { logger.log(Level.SEVERE, "Interrupted while building suggesters", e); @@ -235,7 +235,7 @@ public void rebuild(final Collection indexDirs) { } synchronized (lock) { - long startTime = System.currentTimeMillis(); + Instant start = Instant.now(); logger.log(Level.INFO, "Rebuilding the following suggesters: {0}", indexDirs); ExecutorService executor = Executors.newWorkStealingPool(rebuildParallelismLevel); @@ -249,7 +249,7 @@ public void rebuild(final Collection indexDirs) { } } - shutdownAndAwaitTermination(executor, startTime, "Suggesters for " + indexDirs + " were successfully rebuilt"); + shutdownAndAwaitTermination(executor, start, "Suggesters for " + indexDirs + " were successfully rebuilt"); } } From cd1a06003dfc5b4b26d280c4e02738a5b75527e0 Mon Sep 17 00:00:00 2001 From: Vladimir Kotal Date: Tue, 13 Aug 2019 15:24:16 +0200 Subject: [PATCH 5/5] fmt --- suggester/src/main/java/org/opengrok/suggest/Suggester.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/suggester/src/main/java/org/opengrok/suggest/Suggester.java b/suggester/src/main/java/org/opengrok/suggest/Suggester.java index ceae9017065..23f6ae721a0 100644 --- a/suggester/src/main/java/org/opengrok/suggest/Suggester.java +++ b/suggester/src/main/java/org/opengrok/suggest/Suggester.java @@ -215,9 +215,9 @@ private void shutdownAndAwaitTermination(final ExecutorService executorService, executorService.shutdown(); try { executorService.awaitTermination(awaitTerminationTime.toMillis(), TimeUnit.MILLISECONDS); - logger.log(Level.INFO, logMessageOnSuccess + " (took {0})", + logger.log(Level.INFO, "{0} (took {1})", new Object[]{logMessageOnSuccess, DurationFormatUtils.formatDurationWords(Duration.between(start, Instant.now()).toMillis(), - true, true)); + true, true)}); } catch (InterruptedException e) { logger.log(Level.SEVERE, "Interrupted while building suggesters", e); Thread.currentThread().interrupt();