Author: gdusbabek
Date: Fri Feb 5 18:41:55 2010
New Revision: 907044
URL: http://svn.apache.org/viewvc?rev=907044&view=rev
Log:
track latency in nanoseconds, measure in microseconds. patch by Gary Dusbabek,
reviewed by Jonathan Ellis. CASSANDRA-733
Modified:
incubator/cassandra/trunk/CHANGES.txt
incubator/cassandra/trunk/src/java/org/apache/cassandra/db/ColumnFamilyStore.java
incubator/cassandra/trunk/src/java/org/apache/cassandra/db/ColumnFamilyStoreMBean.java
incubator/cassandra/trunk/src/java/org/apache/cassandra/service/StorageProxy.java
incubator/cassandra/trunk/src/java/org/apache/cassandra/service/StorageProxyMBean.java
incubator/cassandra/trunk/src/java/org/apache/cassandra/tools/NodeCmd.java
incubator/cassandra/trunk/src/java/org/apache/cassandra/utils/LatencyTracker.java
Modified: incubator/cassandra/trunk/CHANGES.txt
URL:
http://svn.apache.org/viewvc/incubator/cassandra/trunk/CHANGES.txt?rev=907044&r1=907043&r2=907044&view=diff
==============================================================================
--- incubator/cassandra/trunk/CHANGES.txt (original)
+++ incubator/cassandra/trunk/CHANGES.txt Fri Feb 5 18:41:55 2010
@@ -20,6 +20,7 @@
instead of average over the last minute (CASSANDRA-702)
* support get_range_slice for RandomPartitioner (CASSANDRA-745)
* per-keyspace replication factory and replication strategy (CASSANDRA-620)
+ * track latency in nanoseconds (CASSANDRA-733)
0.5.1
Modified:
incubator/cassandra/trunk/src/java/org/apache/cassandra/db/ColumnFamilyStore.java
URL:
http://svn.apache.org/viewvc/incubator/cassandra/trunk/src/java/org/apache/cassandra/db/ColumnFamilyStore.java?rev=907044&r1=907043&r2=907044&view=diff
==============================================================================
---
incubator/cassandra/trunk/src/java/org/apache/cassandra/db/ColumnFamilyStore.java
(original)
+++
incubator/cassandra/trunk/src/java/org/apache/cassandra/db/ColumnFamilyStore.java
Fri Feb 5 18:41:55 2010
@@ -441,11 +441,11 @@
*/
Memtable apply(String key, ColumnFamily columnFamily) throws IOException
{
- long start = System.currentTimeMillis();
+ long start = System.nanoTime();
boolean flushRequested = memtable_.isThresholdViolated();
memtable_.put(key, columnFamily);
- writeStats_.add(System.currentTimeMillis() - start);
+ writeStats_.addNano(System.nanoTime() - start);
return flushRequested ? memtable_ : null;
}
@@ -457,9 +457,9 @@
*/
void applyBinary(String key, byte[] buffer) throws IOException
{
- long start = System.currentTimeMillis();
+ long start = System.nanoTime();
binaryMemtable_.get().put(key, buffer);
- writeStats_.add(System.currentTimeMillis() - start);
+ writeStats_.addNano(System.nanoTime() - start);
}
/*
@@ -746,14 +746,14 @@
return readStats_.getOpCount();
}
- public double getRecentReadLatency()
+ public double getRecentReadLatencyMicros()
{
- return readStats_.getRecentLatency();
+ return readStats_.getRecentLatencyMicros();
}
- public long getTotalReadLatency()
+ public long getTotalReadLatencyMicros()
{
- return readStats_.getTotalLatency();
+ return readStats_.getTotalLatencyMicros();
}
// TODO this actually isn't a good meature of pending tasks
@@ -767,14 +767,14 @@
return writeStats_.getOpCount();
}
- public long getTotalWriteLatency()
+ public long getTotalWriteLatencyMicros()
{
- return writeStats_.getTotalLatency();
+ return writeStats_.getTotalLatencyMicros();
}
- public double getRecentWriteLatency()
+ public double getRecentWriteLatencyMicros()
{
- return writeStats_.getRecentLatency();
+ return writeStats_.getRecentLatencyMicros();
}
public ColumnFamily getColumnFamily(String key, QueryPath path, byte[]
start, byte[] finish, boolean reversed, int limit) throws IOException
@@ -809,7 +809,7 @@
{
assert columnFamily_.equals(filter.getColumnFamilyName());
- long start = System.currentTimeMillis();
+ long start = System.nanoTime();
try
{
if (filter.path.superColumnName == null)
@@ -855,7 +855,7 @@
}
finally
{
- readStats_.add(System.currentTimeMillis() - start);
+ readStats_.addNano(System.nanoTime() - start);
}
}
Modified:
incubator/cassandra/trunk/src/java/org/apache/cassandra/db/ColumnFamilyStoreMBean.java
URL:
http://svn.apache.org/viewvc/incubator/cassandra/trunk/src/java/org/apache/cassandra/db/ColumnFamilyStoreMBean.java?rev=907044&r1=907043&r2=907044&view=diff
==============================================================================
---
incubator/cassandra/trunk/src/java/org/apache/cassandra/db/ColumnFamilyStoreMBean.java
(original)
+++
incubator/cassandra/trunk/src/java/org/apache/cassandra/db/ColumnFamilyStoreMBean.java
Fri Feb 5 18:41:55 2010
@@ -67,12 +67,12 @@
/**
* @return total read latency (divide by getReadCount() for average)
*/
- public long getTotalReadLatency();
+ public long getTotalReadLatencyMicros();
/**
* @return average latency per read operation since the last call
*/
- public double getRecentReadLatency();
+ public double getRecentReadLatencyMicros();
/**
* @return the number of write operations on this column family
@@ -82,12 +82,12 @@
/**
* @return total write latency (divide by getReadCount() for average)
*/
- public long getTotalWriteLatency();
+ public long getTotalWriteLatencyMicros();
/**
* @return average latency per write operation since the last call
*/
- public double getRecentWriteLatency();
+ public double getRecentWriteLatencyMicros();
/**
* @return the estimated number of tasks pending for this column family
Modified:
incubator/cassandra/trunk/src/java/org/apache/cassandra/service/StorageProxy.java
URL:
http://svn.apache.org/viewvc/incubator/cassandra/trunk/src/java/org/apache/cassandra/service/StorageProxy.java?rev=907044&r1=907043&r2=907044&view=diff
==============================================================================
---
incubator/cassandra/trunk/src/java/org/apache/cassandra/service/StorageProxy.java
(original)
+++
incubator/cassandra/trunk/src/java/org/apache/cassandra/service/StorageProxy.java
Fri Feb 5 18:41:55 2010
@@ -98,7 +98,7 @@
*/
public static void mutate(List<RowMutation> mutations)
{
- long startTime = System.currentTimeMillis();
+ long startTime = System.nanoTime();
try
{
for (final RowMutation rm: mutations)
@@ -159,13 +159,13 @@
}
finally
{
- writeStats.add(System.currentTimeMillis() - startTime);
+ writeStats.addNano(System.nanoTime() - startTime);
}
}
public static void mutateBlocking(List<RowMutation> mutations,
ConsistencyLevel consistency_level) throws UnavailableException,
TimeoutException
{
- long startTime = System.currentTimeMillis();
+ long startTime = System.nanoTime();
ArrayList<WriteResponseHandler> responseHandlers = new
ArrayList<WriteResponseHandler>();
RowMutation mostRecentRowMutation = null;
@@ -238,7 +238,7 @@
}
finally
{
- writeStats.add(System.currentTimeMillis() - startTime);
+ writeStats.addNano(System.nanoTime() - startTime);
}
}
@@ -365,7 +365,7 @@
public static List<Row> readProtocol(List<ReadCommand> commands,
ConsistencyLevel consistency_level)
throws IOException, UnavailableException, TimeoutException
{
- long startTime = System.currentTimeMillis();
+ long startTime = System.nanoTime();
List<Row> rows = new ArrayList<Row>();
@@ -400,7 +400,7 @@
rows = strongRead(commands, consistency_level);
}
- readStats.add(System.currentTimeMillis() - startTime);
+ readStats.addNano(System.nanoTime() - startTime);
return rows;
}
@@ -535,7 +535,7 @@
public static List<Pair<String, ColumnFamily>>
getRangeSlice(RangeSliceCommand command, ConsistencyLevel consistency_level)
throws IOException, UnavailableException, TimeoutException
{
- long startTime = System.currentTimeMillis();
+ long startTime = System.nanoTime();
TokenMetadata tokenMetadata =
StorageService.instance.getTokenMetadata();
InetAddress endPoint =
StorageService.instance.getPrimary(command.startKey.token);
@@ -608,7 +608,7 @@
return keyComparator.compare(o1.left, o2.left);
}
});
- rangeStats.add(System.currentTimeMillis() - startTime);
+ rangeStats.addNano(System.nanoTime() - startTime);
return results;
}
@@ -617,14 +617,14 @@
return readStats.getOpCount();
}
- public long getTotalReadLatency()
+ public long getTotalReadLatencyMicros()
{
- return readStats.getTotalLatency();
+ return readStats.getTotalLatencyMicros();
}
- public double getRecentReadLatency()
+ public double getRecentReadLatencyMicros()
{
- return readStats.getRecentLatency();
+ return readStats.getRecentLatencyMicros();
}
public long getRangeOperations()
@@ -632,14 +632,14 @@
return rangeStats.getOpCount();
}
- public long getTotalRangeLatency()
+ public long getTotalRangeLatencyMicros()
{
- return rangeStats.getTotalLatency();
+ return rangeStats.getTotalLatencyMicros();
}
- public double getRecentRangeLatency()
+ public double getRecentRangeLatencyMicros()
{
- return rangeStats.getRecentLatency();
+ return rangeStats.getRecentLatencyMicros();
}
public long getWriteOperations()
@@ -647,14 +647,14 @@
return writeStats.getOpCount();
}
- public long getTotalWriteLatency()
+ public long getTotalWriteLatencyMicros()
{
- return writeStats.getTotalLatency();
+ return writeStats.getTotalLatencyMicros();
}
- public double getRecentWriteLatency()
+ public double getRecentWriteLatencyMicros()
{
- return writeStats.getRecentLatency();
+ return writeStats.getRecentLatencyMicros();
}
static class weakReadLocalCallable implements Callable<Object>
Modified:
incubator/cassandra/trunk/src/java/org/apache/cassandra/service/StorageProxyMBean.java
URL:
http://svn.apache.org/viewvc/incubator/cassandra/trunk/src/java/org/apache/cassandra/service/StorageProxyMBean.java?rev=907044&r1=907043&r2=907044&view=diff
==============================================================================
---
incubator/cassandra/trunk/src/java/org/apache/cassandra/service/StorageProxyMBean.java
(original)
+++
incubator/cassandra/trunk/src/java/org/apache/cassandra/service/StorageProxyMBean.java
Fri Feb 5 18:41:55 2010
@@ -21,14 +21,14 @@
public interface StorageProxyMBean
{
public long getReadOperations();
- public long getTotalReadLatency();
- public double getRecentReadLatency();
+ public long getTotalReadLatencyMicros();
+ public double getRecentReadLatencyMicros();
public long getRangeOperations();
- public long getTotalRangeLatency();
- public double getRecentRangeLatency();
+ public long getTotalRangeLatencyMicros();
+ public double getRecentRangeLatencyMicros();
public long getWriteOperations();
- public long getTotalWriteLatency();
- public double getRecentWriteLatency();
+ public long getTotalWriteLatencyMicros();
+ public double getRecentWriteLatencyMicros();
}
Modified:
incubator/cassandra/trunk/src/java/org/apache/cassandra/tools/NodeCmd.java
URL:
http://svn.apache.org/viewvc/incubator/cassandra/trunk/src/java/org/apache/cassandra/tools/NodeCmd.java?rev=907044&r1=907043&r2=907044&view=diff
==============================================================================
--- incubator/cassandra/trunk/src/java/org/apache/cassandra/tools/NodeCmd.java
(original)
+++ incubator/cassandra/trunk/src/java/org/apache/cassandra/tools/NodeCmd.java
Fri Feb 5 18:41:55 2010
@@ -217,18 +217,18 @@
if (readCount > 0)
{
tableReadCount += readCount;
- tableTotalReadTime += cfstore.getTotalReadLatency();
+ tableTotalReadTime += cfstore.getTotalReadLatencyMicros();
}
if (writeCount > 0)
{
tableWriteCount += writeCount;
- tableTotalWriteTime += cfstore.getTotalWriteLatency();
+ tableTotalWriteTime +=
cfstore.getTotalWriteLatencyMicros();
}
tablePendingTasks += cfstore.getPendingTasks();
}
- double tableReadLatency = tableReadCount > 0 ? tableTotalReadTime
/ tableReadCount : Double.NaN;
- double tableWriteLatency = tableWriteCount > 0 ?
tableTotalWriteTime / tableWriteCount : Double.NaN;
+ double tableReadLatency = tableReadCount > 0 ? tableTotalReadTime
/ tableReadCount / 1000 : Double.NaN;
+ double tableWriteLatency = tableWriteCount > 0 ?
tableTotalWriteTime / tableWriteCount / 1000 : Double.NaN;
outs.println("\tRead Count: " + tableReadCount);
outs.println("\tRead Latency: " + String.format("%s",
tableReadLatency) + " ms.");
@@ -247,9 +247,9 @@
outs.println("\t\tMemtable Data Size: " +
cfstore.getMemtableDataSize());
outs.println("\t\tMemtable Switch Count: " +
cfstore.getMemtableSwitchCount());
outs.println("\t\tRead Count: " + cfstore.getReadCount());
- outs.println("\t\tRead Latency: " + String.format("%01.3f",
cfstore.getRecentReadLatency()) + " ms.");
+ outs.println("\t\tRead Latency: " + String.format("%01.3f",
cfstore.getRecentReadLatencyMicros() / 1000) + " ms.");
outs.println("\t\tWrite Count: " + cfstore.getWriteCount());
- outs.println("\t\tWrite Latency: " + String.format("%01.3f",
cfstore.getRecentWriteLatency()) + " ms.");
+ outs.println("\t\tWrite Latency: " + String.format("%01.3f",
cfstore.getRecentWriteLatencyMicros() / 1000) + " ms.");
outs.println("\t\tPending Tasks: " +
cfstore.getPendingTasks());
JMXAggregatingCacheMBean keyCacheMBean =
probe.getKeyCacheMBean(tableName, cfstore.getColumnFamilyName());
Modified:
incubator/cassandra/trunk/src/java/org/apache/cassandra/utils/LatencyTracker.java
URL:
http://svn.apache.org/viewvc/incubator/cassandra/trunk/src/java/org/apache/cassandra/utils/LatencyTracker.java?rev=907044&r1=907043&r2=907044&view=diff
==============================================================================
---
incubator/cassandra/trunk/src/java/org/apache/cassandra/utils/LatencyTracker.java
(original)
+++
incubator/cassandra/trunk/src/java/org/apache/cassandra/utils/LatencyTracker.java
Fri Feb 5 18:41:55 2010
@@ -1,42 +1,51 @@
-package org.apache.cassandra.utils;
-
-import java.util.concurrent.atomic.AtomicLong;
-
-public class LatencyTracker
-{
- private final AtomicLong opCount = new AtomicLong(0);
- private final AtomicLong totalLatency = new AtomicLong(0);
- private long lastLatency = 0;
- private long lastOpCount = 0;
-
- public void add(long n)
- {
- opCount.incrementAndGet();
- totalLatency.addAndGet(n);
- }
-
- public long getOpCount()
- {
- return opCount.get();
- }
-
- public long getTotalLatency()
- {
- return totalLatency.get();
- }
-
- public double getRecentLatency()
- {
- long ops = opCount.get();
- long n = totalLatency.get();
- try
- {
- return ((double)n - lastLatency) / (ops - lastOpCount);
- }
- finally
- {
- lastLatency = n;
- lastOpCount = ops;
- }
- }
-}
+package org.apache.cassandra.utils;
+
+import java.util.concurrent.atomic.AtomicLong;
+
+public class LatencyTracker
+{
+ private final AtomicLong opCount = new AtomicLong(0);
+ private final AtomicLong totalLatency = new AtomicLong(0);
+ private long lastLatency = 0;
+ private long lastOpCount = 0;
+
+ /** takes nanoseconds **/
+ public void addNano(long nanos)
+ {
+ // convert to microseconds. 1 millionth
+ addMicro(nanos / 1000);
+ }
+
+ public void addMicro(long micros)
+ {
+ opCount.incrementAndGet();
+ totalLatency.addAndGet(micros);
+ }
+
+ public long getOpCount()
+ {
+ return opCount.get();
+ }
+
+ /** returns microseconds */
+ public long getTotalLatencyMicros()
+ {
+ return totalLatency.get();
+ }
+
+ /** returns microseconds */
+ public double getRecentLatencyMicros()
+ {
+ long ops = opCount.get();
+ long n = totalLatency.get();
+ try
+ {
+ return ((double)n - lastLatency) / (ops - lastOpCount);
+ }
+ finally
+ {
+ lastLatency = n;
+ lastOpCount = ops;
+ }
+ }
+}
