You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cloudstack.apache.org by da...@apache.org on 2015/06/24 09:36:55 UTC
[2/3] git commit: updated refs/heads/master to cbf5155
Offer a getDurationInMillis() method in the Profiler utility class
- New implementation uses nanoseconds. Due to that, the places where the Profiler is used as a Monitor and/or
a stopwatch will suffer with the difference in the return
- Also added a getDuration(), which returns the time in nanoseconds in case someone wants to use it instead
- Added an extra test to check if the getDuration() works fine with nanoseconds
- Fixed the test that checks the time in milliseconds: I added an error margin to cover the test better
Signed-off-by: Daan Hoogland <da...@onecht.net>
Project: http://git-wip-us.apache.org/repos/asf/cloudstack/repo
Commit: http://git-wip-us.apache.org/repos/asf/cloudstack/commit/5557ad55
Tree: http://git-wip-us.apache.org/repos/asf/cloudstack/tree/5557ad55
Diff: http://git-wip-us.apache.org/repos/asf/cloudstack/diff/5557ad55
Branch: refs/heads/master
Commit: 5557ad55880f981c2621a4f411b80e4301469104
Parents: e3daa10
Author: wilderrodrigues <wr...@schubergphilis.com>
Authored: Tue Jun 23 15:46:53 2015 +0200
Committer: Daan Hoogland <da...@onecht.net>
Committed: Wed Jun 24 09:36:40 2015 +0200
----------------------------------------------------------------------
.../agent/manager/SynchronousListener.java | 2 +-
.../db/src/com/cloud/utils/db/GlobalLock.java | 2 +-
.../test/com/cloud/utils/db/GlobalLockTest.java | 2 +-
.../security/SecurityGroupManagerImpl2.java | 2 +-
.../security/SecurityGroupManagerImpl2Test.java | 2 +-
.../security/SecurityGroupQueueTest.java | 2 +-
utils/src/com/cloud/utils/Profiler.java | 53 +++++++++++++++-----
utils/test/com/cloud/utils/TestProfiler.java | 34 ++++++++++---
8 files changed, 74 insertions(+), 25 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/cloudstack/blob/5557ad55/engine/orchestration/src/com/cloud/agent/manager/SynchronousListener.java
----------------------------------------------------------------------
diff --git a/engine/orchestration/src/com/cloud/agent/manager/SynchronousListener.java b/engine/orchestration/src/com/cloud/agent/manager/SynchronousListener.java
index 5da1b27..28c60c1 100644
--- a/engine/orchestration/src/com/cloud/agent/manager/SynchronousListener.java
+++ b/engine/orchestration/src/com/cloud/agent/manager/SynchronousListener.java
@@ -116,7 +116,7 @@ public class SynchronousListener implements Listener {
profiler.stop();
if (s_logger.isTraceEnabled()) {
- s_logger.trace("Synchronized command - sending completed, time: " + profiler.getDuration() + ", answer: " +
+ s_logger.trace("Synchronized command - sending completed, time: " + profiler.getDurationInMillis() + ", answer: " +
(_answers != null ? _answers[0].toString() : "null"));
}
return _answers;
http://git-wip-us.apache.org/repos/asf/cloudstack/blob/5557ad55/framework/db/src/com/cloud/utils/db/GlobalLock.java
----------------------------------------------------------------------
diff --git a/framework/db/src/com/cloud/utils/db/GlobalLock.java b/framework/db/src/com/cloud/utils/db/GlobalLock.java
index e03da53..662ba92 100644
--- a/framework/db/src/com/cloud/utils/db/GlobalLock.java
+++ b/framework/db/src/com/cloud/utils/db/GlobalLock.java
@@ -139,7 +139,7 @@ public class GlobalLock {
}
profiler.stop();
- remainingMilliSeconds -= profiler.getDuration();
+ remainingMilliSeconds -= profiler.getDurationInMillis();
if (remainingMilliSeconds < 0)
return false;
http://git-wip-us.apache.org/repos/asf/cloudstack/blob/5557ad55/framework/db/test/com/cloud/utils/db/GlobalLockTest.java
----------------------------------------------------------------------
diff --git a/framework/db/test/com/cloud/utils/db/GlobalLockTest.java b/framework/db/test/com/cloud/utils/db/GlobalLockTest.java
index c26f248..58c496f 100644
--- a/framework/db/test/com/cloud/utils/db/GlobalLockTest.java
+++ b/framework/db/test/com/cloud/utils/db/GlobalLockTest.java
@@ -49,7 +49,7 @@ public class GlobalLockTest {
p.start();
locked = WorkLock.lock(timeoutSeconds);
p.stop();
- System.out.println("Thread " + id + " waited " + p.getDuration() + " ms, locked=" + locked);
+ System.out.println("Thread " + id + " waited " + p.getDurationInMillis() + " ms, locked=" + locked);
if (locked) {
Thread.sleep(jobDuration * 1000);
}
http://git-wip-us.apache.org/repos/asf/cloudstack/blob/5557ad55/server/src/com/cloud/network/security/SecurityGroupManagerImpl2.java
----------------------------------------------------------------------
diff --git a/server/src/com/cloud/network/security/SecurityGroupManagerImpl2.java b/server/src/com/cloud/network/security/SecurityGroupManagerImpl2.java
index 3c0c5c3..47f6e77 100644
--- a/server/src/com/cloud/network/security/SecurityGroupManagerImpl2.java
+++ b/server/src/com/cloud/network/security/SecurityGroupManagerImpl2.java
@@ -125,7 +125,7 @@ public class SecurityGroupManagerImpl2 extends SecurityGroupManagerImpl {
p.stop();
if (s_logger.isDebugEnabled()) {
s_logger.debug("Security Group Mgr v2: done scheduling ruleset updates for " + workItems.size() + " vms: num new jobs=" + newJobs +
- " num rows insert or updated=" + updated + " time taken=" + p.getDuration());
+ " num rows insert or updated=" + updated + " time taken=" + p.getDurationInMillis());
}
}
http://git-wip-us.apache.org/repos/asf/cloudstack/blob/5557ad55/server/test/com/cloud/network/security/SecurityGroupManagerImpl2Test.java
----------------------------------------------------------------------
diff --git a/server/test/com/cloud/network/security/SecurityGroupManagerImpl2Test.java b/server/test/com/cloud/network/security/SecurityGroupManagerImpl2Test.java
index 9c41ac2..ad1da32 100644
--- a/server/test/com/cloud/network/security/SecurityGroupManagerImpl2Test.java
+++ b/server/test/com/cloud/network/security/SecurityGroupManagerImpl2Test.java
@@ -61,7 +61,7 @@ public class SecurityGroupManagerImpl2Test extends TestCase {
_sgMgr.scheduleRulesetUpdateToHosts(work, false, null);
profiler.stop();
- System.out.println("Done " + numVms + " in " + profiler.getDuration() + " ms");
+ System.out.println("Done " + numVms + " in " + profiler.getDurationInMillis() + " ms");
}
@Test
http://git-wip-us.apache.org/repos/asf/cloudstack/blob/5557ad55/server/test/com/cloud/network/security/SecurityGroupQueueTest.java
----------------------------------------------------------------------
diff --git a/server/test/com/cloud/network/security/SecurityGroupQueueTest.java b/server/test/com/cloud/network/security/SecurityGroupQueueTest.java
index 6c104c2..e90cc58 100644
--- a/server/test/com/cloud/network/security/SecurityGroupQueueTest.java
+++ b/server/test/com/cloud/network/security/SecurityGroupQueueTest.java
@@ -131,7 +131,7 @@ public class SecurityGroupQueueTest extends TestCase {
}
}
p.stop();
- System.out.println("Num Vms= " + maxVmId + " Queue size = " + queue.size() + " time=" + p.getDuration() + " ms");
+ System.out.println("Num Vms= " + maxVmId + " Queue size = " + queue.size() + " time=" + p.getDurationInMillis() + " ms");
assertEquals(maxVmId, queue.size());
}
http://git-wip-us.apache.org/repos/asf/cloudstack/blob/5557ad55/utils/src/com/cloud/utils/Profiler.java
----------------------------------------------------------------------
diff --git a/utils/src/com/cloud/utils/Profiler.java b/utils/src/com/cloud/utils/Profiler.java
index 6082a92..5977453 100644
--- a/utils/src/com/cloud/utils/Profiler.java
+++ b/utils/src/com/cloud/utils/Profiler.java
@@ -20,45 +20,72 @@
package com.cloud.utils;
public class Profiler {
- private Long startTickInMs;
- private Long stopTickInMs;
+
+ private static final long MILLIS_FACTOR = 1000l;
+ private static final double EXPONENT = 2d;
+
+
+ private Long startTickNanoSeconds;
+ private Long stopTickNanoSeconds;
public long start() {
- startTickInMs = System.nanoTime();
- return startTickInMs.longValue();
+ startTickNanoSeconds = System.nanoTime();
+ return startTickNanoSeconds;
}
public long stop() {
- stopTickInMs = System.nanoTime();
- return stopTickInMs.longValue();
+ stopTickNanoSeconds = System.nanoTime();
+ return stopTickNanoSeconds;
}
+ /**
+ * 1 millisecond = 1e+6 nanoseconds
+ * 1 second = 1000 milliseconds = 1e+9 nanoseconds
+ *
+ * @return the duration in nanoseconds.
+ */
public long getDuration() {
- if (startTickInMs != null && stopTickInMs != null) {
- return stopTickInMs.longValue() - startTickInMs.longValue();
+ if (startTickNanoSeconds != null && stopTickNanoSeconds != null) {
+ final long timeInMicroSeconds = stopTickNanoSeconds - startTickNanoSeconds;
+ return timeInMicroSeconds;
+ }
+
+ return -1;
+ }
+
+ /**
+ * 1 millisecond = 1e+6 nanoseconds
+ * 1 second = 1000 millisecond = 1e+9 nanoseconds
+ *
+ * @return the duration in milliseconds.
+ */
+ public long getDurationInMillis() {
+ if (startTickNanoSeconds != null && stopTickNanoSeconds != null) {
+ final long timeInMillis = (stopTickNanoSeconds - startTickNanoSeconds) / (long)Math.pow(MILLIS_FACTOR, EXPONENT);
+ return timeInMillis;
}
return -1;
}
public boolean isStarted() {
- return startTickInMs != null;
+ return startTickNanoSeconds != null;
}
public boolean isStopped() {
- return stopTickInMs != null;
+ return stopTickNanoSeconds != null;
}
@Override
public String toString() {
- if (startTickInMs == null) {
+ if (startTickNanoSeconds == null) {
return "Not Started";
}
- if (stopTickInMs == null) {
+ if (stopTickNanoSeconds == null) {
return "Started but not stopped";
}
- return "Done. Duration: " + getDuration() + "ms";
+ return "Done. Duration: " + getDurationInMillis() + "ms";
}
}
\ No newline at end of file
http://git-wip-us.apache.org/repos/asf/cloudstack/blob/5557ad55/utils/test/com/cloud/utils/TestProfiler.java
----------------------------------------------------------------------
diff --git a/utils/test/com/cloud/utils/TestProfiler.java b/utils/test/com/cloud/utils/TestProfiler.java
index 4323f1d..cbd28f5 100644
--- a/utils/test/com/cloud/utils/TestProfiler.java
+++ b/utils/test/com/cloud/utils/TestProfiler.java
@@ -28,26 +28,48 @@ import com.cloud.utils.testcase.Log4jEnabledTestCase;
public class TestProfiler extends Log4jEnabledTestCase {
protected final static Logger s_logger = Logger.getLogger(TestProfiler.class);
+ private static final long MILLIS_FACTOR = 1000l;
+ private static final int MARGIN = 100;
+ private static final double EXPONENT = 3d;
+
@Test
- public void testProfiler() {
+ public void testProfilerInMillis() {
s_logger.info("testProfiler() started");
final Profiler pf = new Profiler();
pf.start();
try {
- Thread.sleep(1000);
+ Thread.sleep(MILLIS_FACTOR);
} catch (final InterruptedException e) {
}
pf.stop();
- s_logger.info("Duration : " + pf.getDuration());
+ final long durationInMillis = pf.getDurationInMillis();
+ s_logger.info("Duration : " + durationInMillis);
- Assert.assertTrue(pf.getDuration() >= 1000);
+ // An error margin in order to cover the time taken by the star/stop calls.
+ // 100 milliseconds margin seems too much, but it will avoid assertion error
+ // and also fail in case a duration in nanoseconds is used instead.
+ Assert.assertTrue(durationInMillis >= MILLIS_FACTOR && durationInMillis <= MILLIS_FACTOR + MARGIN);
s_logger.info("testProfiler() stopped");
}
@Test
+ public void testProfilerInMicro() {
+ final Profiler pf = new Profiler();
+ pf.start();
+ try {
+ Thread.sleep(MILLIS_FACTOR);
+ } catch (final InterruptedException e) {
+ }
+ pf.stop();
+
+ final long duration = pf.getDuration();
+ Assert.assertTrue(duration >= Math.pow(MILLIS_FACTOR, EXPONENT));
+ }
+
+ @Test
public void testProfilerNoStart() {
final Profiler pf = new Profiler();
try {
@@ -56,7 +78,7 @@ public class TestProfiler extends Log4jEnabledTestCase {
}
pf.stop();
- Assert.assertTrue(pf.getDuration() == -1);
+ Assert.assertTrue(pf.getDurationInMillis() == -1);
Assert.assertFalse(pf.isStarted());
}
@@ -69,7 +91,7 @@ public class TestProfiler extends Log4jEnabledTestCase {
} catch (final InterruptedException e) {
}
- Assert.assertTrue(pf.getDuration() == -1);
+ Assert.assertTrue(pf.getDurationInMillis() == -1);
Assert.assertFalse(pf.isStopped());
}
}
\ No newline at end of file