diff --git a/sdk/src/main/server-api/sc/framework/plugins/ActionTimeout.java b/sdk/src/main/server-api/sc/framework/plugins/ActionTimeout.java index 263617f61..0a0ca533b 100644 --- a/sdk/src/main/server-api/sc/framework/plugins/ActionTimeout.java +++ b/sdk/src/main/server-api/sc/framework/plugins/ActionTimeout.java @@ -1,127 +1,157 @@ package sc.framework.plugins; +import java.lang.management.ManagementFactory; +import java.lang.management.GarbageCollectorMXBean; + import org.slf4j.Logger; import org.slf4j.LoggerFactory; -// TODO We can probably utilise an inbuilt class instead. /** Tracks timeouts in Milliseconds. */ public class ActionTimeout { - static final Logger logger = LoggerFactory.getLogger(ActionTimeout.class); - - private final long softTimeoutInMilliseconds; - - private final long hardTimeoutInMilliseconds; + static final Logger logger = LoggerFactory.getLogger(ActionTimeout.class); - private final boolean canTimeout; + private final long softTimeoutInMilliseconds; - private Thread timeoutThread; + private final long hardTimeoutInMilliseconds; - private Status status = Status.NEW; + private final boolean canTimeout; - private long startTimestamp = 0; - private long stopTimestamp = 0; + private Thread timeoutThread; - private static final int DEFAULT_HARD_TIMEOUT = 10000; - private static final int DEFAULT_SOFT_TIMEOUT = 5000; + private Status status = Status.NEW; - private enum Status { - NEW, STARTED, STOPPED - } + private long startTimestamp = 0; + private long stopTimestamp = 0; + private long gcStartTime = 0; + private long gcStopTime = 0; - public ActionTimeout(boolean canTimeout) { - this(canTimeout, DEFAULT_HARD_TIMEOUT, DEFAULT_SOFT_TIMEOUT); - } + private static final int DEFAULT_HARD_TIMEOUT = 10000; + private static final int DEFAULT_SOFT_TIMEOUT = 2000; - public ActionTimeout(boolean canTimeout, int hardTimeoutInMilliseconds) { - this(canTimeout, hardTimeoutInMilliseconds, hardTimeoutInMilliseconds); - } + private enum Status { + NEW, STARTED, STOPPED + } - public ActionTimeout(boolean canTimeout, int hardTimeoutInMilliseconds, int softTimeoutInMilliseconds) { - if (hardTimeoutInMilliseconds < softTimeoutInMilliseconds) { - throw new IllegalArgumentException( - "HardTimeout must be greater or equal the SoftTimeout"); + public ActionTimeout(boolean canTimeout) { + this(canTimeout, DEFAULT_HARD_TIMEOUT, DEFAULT_SOFT_TIMEOUT); } - this.canTimeout = canTimeout; - this.softTimeoutInMilliseconds = softTimeoutInMilliseconds; - this.hardTimeoutInMilliseconds = hardTimeoutInMilliseconds; - } + public ActionTimeout(boolean canTimeout, int hardTimeoutInMilliseconds) { + this(canTimeout, hardTimeoutInMilliseconds, hardTimeoutInMilliseconds); + } - public long getHardTimeout() { - return this.hardTimeoutInMilliseconds; - } + public ActionTimeout(boolean canTimeout, int hardTimeoutInMilliseconds, int softTimeoutInMilliseconds) { + if (hardTimeoutInMilliseconds < softTimeoutInMilliseconds) { + throw new IllegalArgumentException( + "HardTimeout must be greater or equal the SoftTimeout"); + } - public long getSoftTimeout() { - return this.softTimeoutInMilliseconds; - } + this.canTimeout = canTimeout; + this.softTimeoutInMilliseconds = softTimeoutInMilliseconds; + this.hardTimeoutInMilliseconds = hardTimeoutInMilliseconds; + } - public boolean canTimeout() { - return this.canTimeout; - } + public long getHardTimeout() { + return this.hardTimeoutInMilliseconds; + } - public long getTimeDiff() { - if (this.status == Status.NEW) { - throw new IllegalStateException("Timeout was never started."); + public long getSoftTimeout() { + return this.softTimeoutInMilliseconds; } - if (this.status == Status.STARTED) { - throw new IllegalStateException("Timeout was not stopped."); + public boolean canTimeout() { + return this.canTimeout; } - return stopTimestamp - startTimestamp; - } + public long getTimeDiff() { + if (this.status == Status.NEW) { + throw new IllegalStateException("Timeout was never started."); + } + + if (this.status == Status.STARTED) { + throw new IllegalStateException("Timeout was not stopped."); + } - public synchronized boolean didTimeout() { - return this.canTimeout() && this.getTimeDiff() > this.softTimeoutInMilliseconds; - } - public synchronized void stop() { - if (this.status == Status.NEW) { - throw new IllegalStateException("Timeout was never started."); + logger.info("Garbage collection time: {} {} {}", gcStopTime, gcStartTime, gcStopTime - gcStartTime); + logger.info("Real time difference: {}", stopTimestamp - startTimestamp); + logger.info("Unaltered time difference: {}", stopTimestamp - startTimestamp - gcStopTime + gcStartTime); + // Subtract the garbage collection time for an unaltered time + return stopTimestamp - startTimestamp - gcStopTime + gcStartTime; } - if (this.status == Status.STOPPED) { - logger.warn("Redundant stop: Timeout was already stopped."); - return; + public synchronized boolean didTimeout() { + return this.canTimeout() && this.getTimeDiff() > this.softTimeoutInMilliseconds; } - this.stopTimestamp = System.currentTimeMillis(); - this.status = Status.STOPPED; + public synchronized void stop() { + if (this.status == Status.NEW) { + throw new IllegalStateException("Timeout was never started."); + } + + if (this.status == Status.STOPPED) { + logger.warn("Redundant stop: Timeout was already stopped."); + return; + } + + this.stopTimestamp = System.currentTimeMillis(); + this.status = Status.STOPPED; + + if (this.timeoutThread != null) { + this.timeoutThread.interrupt(); + } - if (this.timeoutThread != null) { - this.timeoutThread.interrupt(); + // Get the garbage collection time + this.gcStopTime = getGCTime(); } - } - public synchronized void start(final Runnable onTimeout) { - if (this.status != Status.NEW) { - throw new IllegalStateException("Redundant start: was already started!"); + public synchronized void start(final Runnable onTimeout) { + if (this.status != Status.NEW) { + throw new IllegalStateException("Redundant start: was already started!"); + } + + if (canTimeout()) { + this.timeoutThread = new Thread(() -> { + try { + Thread.sleep(getHardTimeout()); + stop(); + onTimeout.run(); + } catch (InterruptedException e) { + logger.info("HardTimeout wasn't reached."); + } + }); + + // Get the garbage collection time + this.gcStartTime = getGCTime(); + this.timeoutThread.start(); + } + + this.startTimestamp = System.currentTimeMillis(); + this.status = Status.STARTED; } - if (canTimeout()) { - this.timeoutThread = new Thread(() -> { - try { - Thread.sleep(getHardTimeout()); - stop(); - onTimeout.run(); - } catch (InterruptedException e) { - logger.info("HardTimout wasn't reached."); + /** + * Measures the total garbage collection time. + * This is meant to be used as a value relative to a start time. + * @return The total garbage collection time + */ + private long getGCTime() { + long gcTime = 0; + for (GarbageCollectorMXBean gcBean : ManagementFactory.getGarbageCollectorMXBeans()) { + gcTime += gcBean.getCollectionTime(); } - }); - this.timeoutThread.start(); + return gcTime; } - this.startTimestamp = System.currentTimeMillis(); - this.status = Status.STARTED; - } - - @Override - public String toString() { - return "ActionTimeout{" + - "canTimeout=" + canTimeout + - ", status=" + status + - ", start=" + startTimestamp + - ", stop=" + stopTimestamp + - '}'; - } -} + @Override + public String toString() { + return "ActionTimeout{" + + "canTimeout=" + canTimeout + + ", status=" + status + + ", start=" + startTimestamp + + ", stop=" + stopTimestamp + + ", gcStart=" + gcStartTime + + ", gcStop=" + gcStopTime + + '}'; + } +} \ No newline at end of file