Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 1 | package net.onrc.onos.ofcontroller.flowmanager; |
| 2 | |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 3 | import java.util.ArrayList; |
| 4 | import java.util.List; |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 5 | import java.util.Map; |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 6 | import java.util.Map.Entry; |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 7 | import java.util.concurrent.ConcurrentHashMap; |
| 8 | |
| 9 | import org.slf4j.Logger; |
| 10 | import org.slf4j.LoggerFactory; |
| 11 | |
| 12 | /** |
| 13 | * Class for collecting performance measurements |
| 14 | */ |
| 15 | public class PerformanceMonitor { |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 16 | private final static Map<String, List<Measurement>> map = new ConcurrentHashMap<>();; |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 17 | private final static Logger log = LoggerFactory.getLogger(PerformanceMonitor.class); |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 18 | private static long overhead; |
| 19 | private static long experimentStart = Long.MAX_VALUE; |
| 20 | private final static double normalization = Math.pow(10, 6); |
| 21 | |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 22 | /** |
| 23 | * Start a performance measurement, identified by a tag |
| 24 | * |
| 25 | * Note: Only a single measurement can use the same tag at a time. |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 26 | * ..... not true anymore. |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 27 | * |
| 28 | * @param tag for performance measurement |
| 29 | */ |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 30 | public static Measurement start(String tag) { |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 31 | long start = System.nanoTime(); |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 32 | if(start < experimentStart) { |
| 33 | experimentStart = start; |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 34 | } |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 35 | List<Measurement> list = map.get(tag); |
| 36 | if(list == null) { |
| 37 | list = new ArrayList<Measurement>(); |
| 38 | map.put(tag, list); |
| 39 | } |
| 40 | Measurement m = new Measurement(); |
| 41 | list.add(m); |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 42 | m.start(); |
| 43 | overhead += System.nanoTime() - start; |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 44 | return m; |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 45 | } |
| 46 | |
| 47 | /** |
| 48 | * Stop a performance measurement. |
| 49 | * |
| 50 | * You must have already started a measurement with tag. |
| 51 | * |
| 52 | * @param tag for performance measurement |
| 53 | */ |
| 54 | public static void stop(String tag) { |
| 55 | long time = System.nanoTime(); |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 56 | List<Measurement> list = map.get(tag); |
| 57 | if(list == null) { |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 58 | log.error("Tag {} does not exist", tag); |
| 59 | } |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 60 | else if(list.size() == 1) { |
| 61 | list.get(0).stop(time); |
| 62 | } |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 63 | else { |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 64 | log.error("Tag {} has multiple measurements", tag); |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 65 | } |
| 66 | overhead += System.nanoTime() - time; |
| 67 | } |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 68 | |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 69 | /** |
| 70 | * Clear all performance measurements. |
| 71 | */ |
| 72 | public static void clear() { |
| 73 | map.clear(); |
| 74 | overhead = 0; |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 75 | experimentStart = Long.MAX_VALUE; |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 76 | } |
| 77 | |
| 78 | /** |
| 79 | * Write all performance measurements to the log |
| 80 | */ |
| 81 | public static void report() { |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 82 | String result = "Performance Results: (avg/start/stop/count)\n"; |
| 83 | long experimentEnd = -1; |
| 84 | for(Entry<String, List<Measurement>> e : map.entrySet()) { |
| 85 | String key = e.getKey(); |
| 86 | List<Measurement> list = e.getValue(); |
| 87 | int total = 0, count = 0; |
| 88 | long start = Long.MAX_VALUE, stop = -1; |
| 89 | for(Measurement m : list) { |
| 90 | // Collect overall start and end times |
| 91 | if(m.start < start) { |
| 92 | start = m.start; |
| 93 | } |
| 94 | if(m.stop > stop) { |
| 95 | stop = m.stop; |
| 96 | if(stop > experimentEnd) { |
| 97 | experimentEnd = stop; |
| 98 | } |
| 99 | } |
| 100 | |
| 101 | // Collect statistics for average |
| 102 | total += m.elapsed(); |
| 103 | count++; |
| 104 | } |
| 105 | double avg = (double) total / count; |
| 106 | // Normalize start/stop |
| 107 | start -= experimentStart; |
| 108 | stop -= experimentStart; |
| 109 | result += key + '=' + |
| 110 | (avg / normalization) + '/' + |
| 111 | (start / normalization) + '/' + |
| 112 | (stop / normalization) + '/' + |
| 113 | count + '\n'; |
| 114 | } |
| 115 | double overheadMs = overhead / normalization; |
| 116 | double experimentElapsed = (experimentEnd - experimentStart) / normalization; |
| 117 | result += "TotalTime:" + experimentElapsed + "/Overhead:" + overheadMs; |
| 118 | log.error(result); |
| 119 | // log.error("Performance Results: {} with measurement overhead: {} ms", map, overheadMilli); |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 120 | } |
Pavlin Radoslavov | b5e3178 | 2014-01-12 20:11:46 -0800 | [diff] [blame] | 121 | |
| 122 | /** |
| 123 | * Write the performance measurement for a tag to the log |
| 124 | * |
| 125 | * @param tag the tag name. |
| 126 | */ |
| 127 | public static void report(String tag) { |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 128 | List<Measurement> list = map.get(tag); |
| 129 | if(list == null) { |
| 130 | return; //TODO |
| 131 | } |
| 132 | //TODO: fix this; |
| 133 | Measurement m = list.get(0); |
Pavlin Radoslavov | b5e3178 | 2014-01-12 20:11:46 -0800 | [diff] [blame] | 134 | if (m != null) { |
| 135 | log.error("Performance Results: tag = {} start = {} stop = {} elapsed = {}", |
| 136 | tag, m.start, m.stop, m.toString()); |
| 137 | } else { |
| 138 | log.error("Performance Results: unknown tag {}", tag); |
| 139 | } |
| 140 | } |
| 141 | |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 142 | /** |
| 143 | * A single performance measurement |
| 144 | */ |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 145 | public static class Measurement { |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 146 | long start; |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 147 | long stop = -1; |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 148 | |
| 149 | /** |
| 150 | * Start the measurement |
| 151 | */ |
| 152 | public void start() { |
| 153 | start = System.nanoTime(); |
| 154 | } |
| 155 | |
| 156 | /** |
| 157 | * Stop the measurement |
| 158 | */ |
| 159 | public void stop() { |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 160 | long now = System.nanoTime(); |
| 161 | stop(now); |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 162 | } |
| 163 | |
| 164 | /** |
| 165 | * Stop the measurement at a specific time |
| 166 | * @param time to stop |
| 167 | */ |
| 168 | public void stop(long time){ |
| 169 | stop = time; |
| 170 | } |
| 171 | |
| 172 | /** |
| 173 | * Compute the elapsed time of the measurement in nanoseconds |
| 174 | * |
| 175 | * @return the measurement time in nanoseconds, or -1 if the measurement is stil running. |
| 176 | */ |
| 177 | public long elapsed() { |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 178 | if(stop <= 0) { |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 179 | return -1; |
| 180 | } |
| 181 | else { |
| 182 | return stop - start; |
| 183 | } |
| 184 | } |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 185 | |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 186 | /** |
| 187 | * Returns the number of milliseconds for the measurement as a String. |
| 188 | */ |
| 189 | public String toString() { |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 190 | double milli = elapsed() / normalization; |
| 191 | double startMs = start / normalization; |
| 192 | double stopMs = stop / normalization; |
| 193 | |
| 194 | return milli + "ms/" + startMs + '/' + stopMs; |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 195 | } |
| 196 | } |
| 197 | |
| 198 | public static void main(String args[]){ |
| 199 | // test the measurement overhead |
| 200 | String tag; |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 201 | for(int i = 0; i < 2; i++){ |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 202 | tag = "foo foo foo"; |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 203 | Measurement m; |
| 204 | m = start(tag); System.out.println(tag); m.stop(); |
| 205 | m = start(tag); System.out.println(tag); m.stop(); |
| 206 | m = start(tag); System.out.println(tag); m.stop(); |
| 207 | m = start(tag); System.out.println(tag); m.stop(); |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 208 | tag = "bar"; |
| 209 | start(tag); stop(tag); |
| 210 | tag = "baz"; |
| 211 | start(tag); stop(tag); |
| 212 | report(); |
| 213 | clear(); |
| 214 | } |
Brian O'Connor | 2daf7a9 | 2014-01-14 11:26:35 -0800 | [diff] [blame^] | 215 | // for(int i = 0; i < 100; i++){ |
| 216 | // tag = "a"; |
| 217 | // start(tag); stop(tag); |
| 218 | // tag = "b"; |
| 219 | // start(tag); stop(tag); |
| 220 | // tag = "c"; |
| 221 | // start(tag); stop(tag); |
| 222 | // report(); |
| 223 | // clear(); |
| 224 | // } |
Brian O'Connor | 8fdfb06 | 2014-01-08 17:47:57 -0800 | [diff] [blame] | 225 | } |
| 226 | } |