diff --git a/core/src/main/java/com/yahoo/ycsb/Client.java b/core/src/main/java/com/yahoo/ycsb/Client.java index 14d8e41bb1e51f1d26f190614513caa03c50d6b7..f68352f4cc67f365e98a105221ef2694bd89be17 100644 --- a/core/src/main/java/com/yahoo/ycsb/Client.java +++ b/core/src/main/java/com/yahoo/ycsb/Client.java @@ -275,7 +275,7 @@ class ClientThread extends Thread try { - _measurements.setStartTimeNs(0); + _measurements.setIntendedStartTimeNs(0); _db.cleanup(); } catch (DBException e) @@ -300,7 +300,7 @@ class ClientThread extends Thread long deadline = startTimeNanos + _opsdone*_targetOpsTickNs; sleepUntil(deadline); if(_measureFromIntendedDeadline) - _measurements.setStartTimeNs(deadline); + _measurements.setIntendedStartTimeNs(deadline); } } diff --git a/core/src/main/java/com/yahoo/ycsb/DBWrapper.java b/core/src/main/java/com/yahoo/ycsb/DBWrapper.java index dae8d78498d9040463296f9f248f339cd84eb89e..9882f38183e03ebad654f870de77496594c09f01 100644 --- a/core/src/main/java/com/yahoo/ycsb/DBWrapper.java +++ b/core/src/main/java/com/yahoo/ycsb/DBWrapper.java @@ -69,10 +69,11 @@ public class DBWrapper extends DB */ public void cleanup() throws DBException { - long st=_measurements.startTimeNs(); + long ist=_measurements.getIntendedtartTimeNs(); + long st = System.nanoTime(); _db.cleanup(); long en=System.nanoTime(); - _measurements.measure("CLEANUP", (int)((en-st)/1000)); + measure(ist, st, en); } /** @@ -86,11 +87,12 @@ public class DBWrapper extends DB */ public int read(String table, String key, Set<String> fields, HashMap<String,ByteIterator> result) { - long st=_measurements.startTimeNs(); - int res=_db.read(table,key,fields,result); + long ist=_measurements.getIntendedtartTimeNs(); + long st = System.nanoTime(); + int res=_db.read(table,key,fields,result); long en=System.nanoTime(); - _measurements.measure("READ",(int)((en-st)/1000)); - _measurements.reportReturnCode("READ",res); + measure(ist, st, en); + _measurements.reportReturnCode("READ",res); return res; } @@ -106,13 +108,19 @@ public class DBWrapper extends DB */ public int scan(String table, String startkey, int recordcount, Set<String> fields, Vector<HashMap<String,ByteIterator>> result) { - long st=_measurements.startTimeNs(); - int res=_db.scan(table,startkey,recordcount,fields,result); + long ist=_measurements.getIntendedtartTimeNs(); + long st = System.nanoTime(); + int res=_db.scan(table,startkey,recordcount,fields,result); long en=System.nanoTime(); - _measurements.measure("SCAN",(int)((en-st)/1000)); - _measurements.reportReturnCode("SCAN",res); + measure(ist, st, en); + _measurements.reportReturnCode("SCAN",res); return res; } + + private void measure(long intendedStartTimeNanos, long startTimeNanos, long endTimeNanos) { + _measurements.measure("CLEANUP", (int)((endTimeNanos-startTimeNanos)/1000)); + _measurements.measureIntended("CLEANUP", (int)((endTimeNanos-intendedStartTimeNanos)/1000)); + } /** * Update a record in the database. Any field/value pairs in the specified values HashMap will be written into the record with the specified @@ -125,10 +133,11 @@ public class DBWrapper extends DB */ public int update(String table, String key, HashMap<String,ByteIterator> values) { - long st=_measurements.startTimeNs(); + long ist=_measurements.getIntendedtartTimeNs(); + long st = System.nanoTime(); int res=_db.update(table,key,values); long en=System.nanoTime(); - _measurements.measure("UPDATE",(int)((en-st)/1000)); + measure(ist, st, en); _measurements.reportReturnCode("UPDATE",res); return res; } @@ -144,10 +153,11 @@ public class DBWrapper extends DB */ public int insert(String table, String key, HashMap<String,ByteIterator> values) { - long st=_measurements.startTimeNs(); + long ist=_measurements.getIntendedtartTimeNs(); + long st = System.nanoTime(); int res=_db.insert(table,key,values); long en=System.nanoTime(); - _measurements.measure("INSERT",(int)((en-st)/1000)); + measure(ist, st, en); _measurements.reportReturnCode("INSERT",res); return res; } @@ -161,10 +171,11 @@ public class DBWrapper extends DB */ public int delete(String table, String key) { - long st=_measurements.startTimeNs(); + long ist=_measurements.getIntendedtartTimeNs(); + long st = System.nanoTime(); int res=_db.delete(table,key); long en=System.nanoTime(); - _measurements.measure("DELETE",(int)((en-st)/1000)); + measure(ist, st, en); _measurements.reportReturnCode("DELETE",res); return res; } diff --git a/core/src/main/java/com/yahoo/ycsb/measurements/Measurements.java b/core/src/main/java/com/yahoo/ycsb/measurements/Measurements.java index e0223b017c0c34672429b6d134453f3290b6b45a..dc2e5f3e65c26678ddcb240c3d4e08f343a699a1 100644 --- a/core/src/main/java/com/yahoo/ycsb/measurements/Measurements.java +++ b/core/src/main/java/com/yahoo/ycsb/measurements/Measurements.java @@ -18,7 +18,6 @@ package com.yahoo.ycsb.measurements; import java.io.IOException; -import java.util.HashMap; import java.util.Properties; import java.util.concurrent.ConcurrentHashMap; @@ -57,8 +56,9 @@ public class Measurements return singleton; } - final ConcurrentHashMap<String,OneMeasurement> data; - int measurementType=0; + final ConcurrentHashMap<String,OneMeasurement> opToMesurementMap; + final ConcurrentHashMap<String,OneMeasurement> opToIntendedMesurementMap; + final int measurementType; private Properties _props; @@ -67,7 +67,8 @@ public class Measurements */ public Measurements(Properties props) { - data=new ConcurrentHashMap<String,OneMeasurement>(); + opToMesurementMap=new ConcurrentHashMap<String,OneMeasurement>(); + opToIntendedMesurementMap=new ConcurrentHashMap<String,OneMeasurement>(); _props=props; @@ -79,10 +80,14 @@ public class Measurements else if (mTypeString.equals("hdrhistogram")) { measurementType=1; + } + else if (mTypeString.equals("hdrhistogram+buckethistogram")) + { + measurementType=2; } else { - measurementType=2; + measurementType=3; } } @@ -94,7 +99,10 @@ public class Measurements return new OneMeasurementHistogram(name, _props); case 1: return new OneMeasurementHdrHistogram(name, _props); - + case 2: + return new TwoInOneMeasurement(name, + new OneMeasurementHdrHistogram("Hdr"+name, _props), + new OneMeasurementHistogram("Bucket"+name, _props)); default: return new OneMeasurementTimeSeries(name, _props); } @@ -116,31 +124,26 @@ public class Measurements return new StartTimeHolder(); }; }; - public void setStartTimeNs(long time){ + public void setIntendedStartTimeNs(long time){ tls.get().time=time; } - public long startTimeNs(){ + + public long getIntendedtartTimeNs(){ return tls.get().startTime(); } - /** - * Report a single value of a single metric. E.g. for read latency, operation="READ" and latency is the measured value. - */ + + /** + * Report a single value of a single metric. E.g. for read latency, operation="READ" and latency is the measured + * value. + */ public void measure(String operation, int latency) { - try { - OneMeasurement m = data.get(operation); - if(m == null) { - m = constructOneMeasurement(operation); - OneMeasurement oldM = data.putIfAbsent(operation, m); - if(oldM != null) - { - m = oldM; - } - } + OneMeasurement m = getOpMeasurement(operation); m.measure(latency); } + // This seems like a terribly hacky way to cover up for a bug in the measurement code catch (java.lang.ArrayIndexOutOfBoundsException e) { System.out.println("ERROR: java.lang.ArrayIndexOutOfBoundsException - ignoring and continuing"); @@ -148,23 +151,59 @@ public class Measurements e.printStackTrace(System.out); } } + /** + * Report a single value of a single metric. E.g. for read latency, operation="READ" and latency is the measured + * value. + */ + public void measureIntended(String operation, int latency) + { + try + { + OneMeasurement m = getOpIntendedMeasurement(operation); + m.measure(latency); + } + // This seems like a terribly hacky way to cover up for a bug in the measurement code + catch (java.lang.ArrayIndexOutOfBoundsException e) + { + System.out.println("ERROR: java.lang.ArrayIndexOutOfBoundsException - ignoring and continuing"); + e.printStackTrace(); + e.printStackTrace(System.out); + } + } + private OneMeasurement getOpMeasurement(String operation) { + OneMeasurement m = opToMesurementMap.get(operation); + if(m == null) + { + m = constructOneMeasurement(operation); + OneMeasurement oldM = opToMesurementMap.putIfAbsent(operation, m); + if(oldM != null) + { + m = oldM; + } + } + return m; + } + private OneMeasurement getOpIntendedMeasurement(String operation) { + OneMeasurement m = opToIntendedMesurementMap.get(operation); + if(m == null) + { + m = constructOneMeasurement("Intended-"+operation); + OneMeasurement oldM = opToIntendedMesurementMap.putIfAbsent(operation, m); + if(oldM != null) + { + m = oldM; + } + } + return m; + } /** * Report a return code for a single DB operaiton. */ public void reportReturnCode(String operation, int code) { - if (!data.containsKey(operation)) - { - synchronized(this) - { - if (!data.containsKey(operation)) - { - data.put(operation,constructOneMeasurement(operation)); - } - } - } - data.get(operation).reportReturnCode(code); + OneMeasurement m = getOpMeasurement(operation); + m.reportReturnCode(code); } /** @@ -175,10 +214,14 @@ public class Measurements */ public void exportMeasurements(MeasurementsExporter exporter) throws IOException { - for (OneMeasurement measurement : data.values()) - { - measurement.exportMeasurements(exporter); - } + for (OneMeasurement measurement : opToMesurementMap.values()) + { + measurement.exportMeasurements(exporter); + } + for (OneMeasurement measurement : opToIntendedMesurementMap.values()) + { + measurement.exportMeasurements(exporter); + } } /** @@ -187,11 +230,14 @@ public class Measurements public synchronized String getSummary() { String ret=""; - for (OneMeasurement m : data.values()) + for (OneMeasurement m : opToMesurementMap.values()) { ret+=m.getSummary()+" "; } - + for (OneMeasurement m : opToIntendedMesurementMap.values()) + { + ret+=m.getSummary()+" "; + } return ret; } } diff --git a/core/src/main/java/com/yahoo/ycsb/measurements/OneMeasurementHdrHistogram.java b/core/src/main/java/com/yahoo/ycsb/measurements/OneMeasurementHdrHistogram.java index 1265a65c140ebd7e2bf4c6a1b7539cc8e1d5475b..1ed37733d5dd63573087197e38538df78acebab0 100644 --- a/core/src/main/java/com/yahoo/ycsb/measurements/OneMeasurementHdrHistogram.java +++ b/core/src/main/java/com/yahoo/ycsb/measurements/OneMeasurementHdrHistogram.java @@ -24,16 +24,15 @@ import java.util.Properties; import java.util.concurrent.ConcurrentHashMap; import java.util.concurrent.atomic.AtomicInteger; -import org.HdrHistogram.ConcurrentHistogram; import org.HdrHistogram.Histogram; import org.HdrHistogram.Recorder; import com.yahoo.ycsb.measurements.exporter.MeasurementsExporter; /** - * Take measurements and maintain a histogram of a given metric, such as READ LATENCY. + * Take measurements and maintain a HdrHistogram of a given metric, such as READ LATENCY. * - * @author cooperb + * @author nitsanw * */ public class OneMeasurementHdrHistogram extends OneMeasurement { @@ -69,7 +68,7 @@ public class OneMeasurementHdrHistogram extends OneMeasurement { /** * It appears latency is reported in micros. - * Using {@link ConcurrentHistogram} to support concurrent updates to histogram. + * Using {@link Recorder} to support concurrent updates to histogram. * * @see com.yahoo.ycsb.OneMeasurement#measure(int) */ @@ -84,14 +83,8 @@ public class OneMeasurementHdrHistogram extends OneMeasurement { */ @Override public void exportMeasurements(MeasurementsExporter exporter) throws IOException { - Histogram lastIntervalHistogram = histogram.getIntervalHistogram(); - // add this to the total time histogram. - if (totalHistogram == null) { - totalHistogram = lastIntervalHistogram; - } - else { - totalHistogram.add(lastIntervalHistogram); - } + // accumulate the last interval which was not caught by status thread + getIntervalHistogramAndAccumulate(); exporter.write(getName(), "Operations", totalHistogram.getTotalCount()); exporter.write(getName(), "AverageLatency(us)", totalHistogram.getMean()); exporter.write(getName(), "MinLatency(us)", totalHistogram.getMinValue()); @@ -107,18 +100,12 @@ public class OneMeasurementHdrHistogram extends OneMeasurement { /** * This is called periodically from the StatusThread. There's a single StatusThread per Client process. + * We optionally serialize the interval to log on this opportunity. * @see com.yahoo.ycsb.measurements.OneMeasurement#getSummary() */ @Override public String getSummary() { - Histogram intervalHistogram = histogram.getIntervalHistogram(); - // add this to the total time histogram. - if (totalHistogram == null) { - totalHistogram = intervalHistogram; - } - else { - totalHistogram.add(intervalHistogram); - } + Histogram intervalHistogram = getIntervalHistogramAndAccumulate(); DecimalFormat d = new DecimalFormat("#.##"); return "[" + getName() + ": Count=" + intervalHistogram.getTotalCount() + @@ -131,4 +118,16 @@ public class OneMeasurementHdrHistogram extends OneMeasurement { ", 99.99=" + d.format(intervalHistogram.getValueAtPercentile(99.99)) +"]"; } + private Histogram getIntervalHistogramAndAccumulate() { + Histogram intervalHistogram = histogram.getIntervalHistogram(); + // add this to the total time histogram. + if (totalHistogram == null) { + totalHistogram = intervalHistogram; + } + else { + totalHistogram.add(intervalHistogram); + } + return intervalHistogram; + } + } diff --git a/core/src/main/java/com/yahoo/ycsb/measurements/TwoInOneMeasurement.java b/core/src/main/java/com/yahoo/ycsb/measurements/TwoInOneMeasurement.java new file mode 100644 index 0000000000000000000000000000000000000000..8fdabde088eb8abc8c5a567176fa2c9ff6b4e5fd --- /dev/null +++ b/core/src/main/java/com/yahoo/ycsb/measurements/TwoInOneMeasurement.java @@ -0,0 +1,79 @@ +/** + * Copyright (c) 2010 Yahoo! Inc. All rights reserved. + * + * Licensed under the Apache License, Version 2.0 (the "License"); you + * may not use this file except in compliance with the License. You + * may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or + * implied. See the License for the specific language governing + * permissions and limitations under the License. See accompanying + * LICENSE file. + */ + +package com.yahoo.ycsb.measurements; + +import java.io.IOException; + +import org.HdrHistogram.Recorder; + +import com.yahoo.ycsb.measurements.exporter.MeasurementsExporter; + +/** + * delegates to 2 measuremement instances. + * @author nitsanw + * + */ +public class TwoInOneMeasurement extends OneMeasurement { + final OneMeasurement thing1,thing2; + public TwoInOneMeasurement(String name, OneMeasurement thing1,OneMeasurement thing2) { + super(name); + this.thing1 = thing1; + this.thing2 = thing2; + } + + /** + * No need for synchronization, using CHM to deal with that + * + * @see com.yahoo.ycsb.OneMeasurement#reportReturnCode(int) + */ + public void reportReturnCode(int code) { + thing1.reportReturnCode(code); + } + + /** + * It appears latency is reported in micros. + * Using {@link Recorder} to support concurrent updates to histogram. + * + * @see com.yahoo.ycsb.OneMeasurement#measure(int) + */ + public void measure(int latencyInMicros) { + thing1.measure(latencyInMicros); + thing2.measure(latencyInMicros); + } + + /** + * This is called from a main thread, on orderly termination. + * + * @see com.yahoo.ycsb.measurements.OneMeasurement#exportMeasurements(com.yahoo.ycsb.measurements.exporter.MeasurementsExporter) + */ + @Override + public void exportMeasurements(MeasurementsExporter exporter) throws IOException { + thing1.exportMeasurements(exporter); + thing2.exportMeasurements(exporter); + } + + /** + * This is called periodically from the StatusThread. There's a single StatusThread per Client process. + * We optionally serialize the interval to log on this opportunity. + * @see com.yahoo.ycsb.measurements.OneMeasurement#getSummary() + */ + @Override + public String getSummary() { + return thing1.getSummary() + "\n" + thing2.getSummary(); + } +} diff --git a/core/src/main/java/com/yahoo/ycsb/workloads/CoreWorkload.java b/core/src/main/java/com/yahoo/ycsb/workloads/CoreWorkload.java index ec63c96f9b8235e3dae26d18b1983caea3dfd75c..5e65c18c0c5f9aa571b77c8f97210673febb58a7 100644 --- a/core/src/main/java/com/yahoo/ycsb/workloads/CoreWorkload.java +++ b/core/src/main/java/com/yahoo/ycsb/workloads/CoreWorkload.java @@ -18,6 +18,7 @@ package com.yahoo.ycsb.workloads; import java.util.Properties; + import com.yahoo.ycsb.*; import com.yahoo.ycsb.generator.CounterGenerator; import com.yahoo.ycsb.generator.DiscreteGenerator; @@ -687,8 +688,9 @@ public class CoreWorkload extends Workload HashMap<String,ByteIterator> cells = new HashMap<String,ByteIterator>(); - long st=_measurements.startTimeNs(); - + + long ist=_measurements.getIntendedtartTimeNs(); + long st = System.nanoTime(); db.read(table,keyname,fields,cells); db.update(table,keyname,values); @@ -700,6 +702,7 @@ public class CoreWorkload extends Workload } _measurements .measure("READ-MODIFY-WRITE", (int)((en-st)/1000)); + _measurements .measureIntended("READ-MODIFY-WRITE", (int)((en-ist)/1000)); } public void doTransactionScan(DB db)