From 6e39849e3c1c6a58e482951f4df171f73cb33017 Mon Sep 17 00:00:00 2001 From: Henning Schmiedehausen Date: Sun, 13 Apr 2014 22:46:14 -0700 Subject: [PATCH] Make the JvmPauseAlarm code somewhat nicer. - run as daemon code to not keep the service running - clean the print code to use a period - use nanoTime() - use mogwee executors --- pom.xml | 6 ++ server/pom.xml | 10 +++ .../nesscomputing/server/JvmPauseAlarm.java | 72 +++++++++++-------- 3 files changed, 58 insertions(+), 30 deletions(-) diff --git a/pom.xml b/pom.xml index bef6087..3902fba 100644 --- a/pom.xml +++ b/pom.xml @@ -174,6 +174,12 @@ ${dep.yammer.version} + + com.mogwee + mogwee-executors + 1.2.1 + + com.nesscomputing.components ness-tinyhttp diff --git a/server/pom.xml b/server/pom.xml index dab7dd2..75b7db4 100644 --- a/server/pom.xml +++ b/server/pom.xml @@ -53,6 +53,11 @@ config-magic + + joda-time + joda-time + + com.google.inject guice @@ -63,6 +68,11 @@ guava + + com.mogwee + mogwee-executors + + org.apache.commons commons-lang3 diff --git a/server/src/main/java/com/nesscomputing/server/JvmPauseAlarm.java b/server/src/main/java/com/nesscomputing/server/JvmPauseAlarm.java index a553321..b3c09ff 100644 --- a/server/src/main/java/com/nesscomputing/server/JvmPauseAlarm.java +++ b/server/src/main/java/com/nesscomputing/server/JvmPauseAlarm.java @@ -15,30 +15,54 @@ */ package com.nesscomputing.server; +import static com.google.common.base.Preconditions.checkNotNull; + import java.util.concurrent.ExecutorService; -import java.util.concurrent.Executors; +import java.util.concurrent.LinkedBlockingQueue; +import java.util.concurrent.TimeUnit; -import com.google.common.base.Throwables; import com.google.common.util.concurrent.ThreadFactoryBuilder; import com.google.inject.Inject; import com.google.inject.Singleton; +import com.mogwee.executors.LoggingExecutor; import com.nesscomputing.lifecycle.LifecycleStage; import com.nesscomputing.lifecycle.guice.OnStage; import com.nesscomputing.logging.Log; +import org.joda.time.Period; +import org.joda.time.format.PeriodFormatter; +import org.joda.time.format.PeriodFormatterBuilder; + @Singleton class JvmPauseAlarm implements Runnable { private static final Log LOG = Log.findLog(); - private static final long S_THRESHOLD = 1000; + + private static final PeriodFormatter printFormat = new PeriodFormatterBuilder().printZeroAlways() + .appendSeconds().appendSuffix(" second", "seconds") + .appendSeparator(" and ").printZeroRarelyLast() + .appendMillis().appendSuffix(" millisecond", " milliseconds").toFormatter(); + + private final ExecutorService executor = new LoggingExecutor(1, 1, 0L, TimeUnit.MILLISECONDS, + new LinkedBlockingQueue(), + new ThreadFactoryBuilder().setNameFormat("jvm-pause-alarm").setDaemon(true).build()); + private final JvmPauseAlarmConfig config; + private final long sleepTime; + private final long alarmTime; + + private volatile boolean running = true; + @Inject JvmPauseAlarm(JvmPauseAlarmConfig config) { - this.config = config; + this.config = checkNotNull(config, "config is null"); + + this.sleepTime = config.getCheckTime().getMillis(); + this.alarmTime = config.getPauseAlarmTime().getMillis(); } @OnStage(LifecycleStage.START) @@ -48,48 +72,36 @@ public void start() return; } - ExecutorService executor = Executors.newSingleThreadExecutor(new ThreadFactoryBuilder().setNameFormat("jvm-pause-alarm").build()); executor.submit(this); - executor.shutdown(); } - @Override - public void run() + @OnStage(LifecycleStage.STOP) + public void stop() { - try { - safeRun(); - } catch (Exception e) { - LOG.error(e, "Exiting due to exception"); - throw Throwables.propagate(e); - } + this.running = false; + executor.shutdown(); } - private void safeRun() + @Override + public void run() { - final long sleepTime = config.getCheckTime().getMillis(); - final long alarmTime = config.getPauseAlarmTime().getMillis(); - - LOG.info("Watching JVM for GC pausing. Checking every %s for pauses of at least %s.", - config.getCheckTime(), config.getPauseAlarmTime()); + LOG.info("Watching JVM for GC pausing. Checking every %s for pauses of at least %s.", config.getCheckTime(), config.getPauseAlarmTime()); - long lastUpdate = System.currentTimeMillis(); - while (true) { + do { + final long startNanos = System.nanoTime(); try { Thread.sleep(sleepTime); } catch (InterruptedException e) { Thread.currentThread().interrupt(); - LOG.info("Exiting due to interrupt"); - return; + running = false; } - final long now = System.currentTimeMillis(); - final long pauseMs = now - lastUpdate; + final long pauseMs = TimeUnit.NANOSECONDS.toMillis(System.nanoTime() - startNanos); if (pauseMs > alarmTime) { - LOG.warn("Detected pause of %s!", pauseMs > S_THRESHOLD ? String.format("%.1fs", pauseMs / 1000.0) : pauseMs + "ms"); + final Period gcPeriod = new Period(pauseMs); + LOG.warn("Detected pause of %s!", printFormat.print(gcPeriod)); } - - lastUpdate = now; - } + } while(running); } }