ctf/org.eclipse.tracecompass.tmf.ctf.core.tests/src/org/eclipse/tracecompass/tmf/ctf/core/tests/temp/request/TmfSchedulerBenchmark.java

   1 /*******************************************************************************
   2  * Copyright (c) 2013, 2014 Ericsson
   3  *
   4  * All rights reserved. This program and the accompanying materials are
   5  * made available under the terms of the Eclipse Public License v1.0 which
   6  * accompanies this distribution, and is available at
   7  * http://www.eclipse.org/legal/epl-v10.html
   8  *
   9  * Contributors:
  10  *   Simon Delisle - Initial API and implementation
  11  *******************************************************************************/
  12
  13 package org.eclipse.tracecompass.tmf.ctf.core.tests.temp.request;
  14
  15 import java.io.PrintWriter;
  16
  17 import org.eclipse.tracecompass.testtraces.ctf.CtfTestTrace;
  18 import org.eclipse.tracecompass.tmf.core.event.ITmfEvent;
  19 import org.eclipse.tracecompass.tmf.core.request.ITmfEventRequest;
  20 import org.eclipse.tracecompass.tmf.core.request.TmfEventRequest;
  21 import org.eclipse.tracecompass.tmf.core.timestamp.TmfTimeRange;
  22 import org.eclipse.tracecompass.tmf.ctf.core.tests.shared.CtfTmfTestTraceUtils;
  23 import org.eclipse.tracecompass.tmf.ctf.core.trace.CtfTmfTrace;
  24
  25 /**
  26  * Benchmark for the request scheduler
  27  *
  28  * The benchmark has three tests. The first one is the latency (time between the
  29  * creation of the request and the beginning of its execution). The second one
  30  * is the average waiting time for a request. The last one is the total
  31  * completion time.
  32  */
  33 public class TmfSchedulerBenchmark {
  34
  35     // ------------------------------------------------------------------------
  36     // Constants
  37     // ------------------------------------------------------------------------
  38
  39     private static final int NUM_LOOPS = 10;
  40     private static final int NANOSECONDS_IN_MILLISECONDS = 1000000;
  41     private static final int NANOSECONDS_IN_SECONDS = 1000000000;
  42
  43     // ------------------------------------------------------------------------
  44     // Attributes
  45     // ------------------------------------------------------------------------
  46
  47     private static CtfTmfTrace trace = CtfTmfTestTraceUtils.getTrace(CtfTestTrace.KERNEL);
  48     private static ForegroundRequest lastForegroundRequest = null;
  49     private static BackgroundRequest lastBackgroundRequest = null;
  50
  51     private static PrintWriter pw = new PrintWriter(System.out, true);
  52
  53     /**
  54      * Start the benchmark
  55      *
  56      * @param args
  57      *            The command-line arguments
  58      */
  59     public static void main(final String[] args) {
  60         trace.indexTrace(true);
  61         pw.println("---------- Benchmark started ----------");
  62         latencyBenchmark();
  63         averageWaitingTime();
  64         completedTime();
  65         benchmarkResults();
  66         trace.dispose();
  67     }
  68
  69     private static void latencyBenchmark() {
  70         long averageLatency = 0;
  71
  72         pw.println("----- Latency -----");
  73         for (int i = 0; i < NUM_LOOPS; i++) {
  74             try {
  75                 ForegroundRequest foreground1 = new ForegroundRequest(TmfTimeRange.ETERNITY);
  76                 trace.sendRequest(foreground1);
  77                 foreground1.waitForCompletion();
  78                 averageLatency += foreground1.getLatency();
  79             } catch (InterruptedException e) {
  80                 e.printStackTrace();
  81             }
  82         }
  83         pw.println((averageLatency / NUM_LOOPS) / NANOSECONDS_IN_MILLISECONDS + " ms");
  84     }
  85
  86     private static void averageWaitingTime() {
  87         long averageWaitingBackground = 0;
  88         long averageWaitingForeground1 = 0;
  89         long averageWaitingForeground2 = 0;
  90
  91         pw.println("----- Average waiting time with 3 requests -----");
  92         for (int i = 0; i < NUM_LOOPS; i++) {
  93             ForegroundRequest foreground1 = new ForegroundRequest(TmfTimeRange.ETERNITY);
  94             ForegroundRequest foreground2 = new ForegroundRequest(TmfTimeRange.ETERNITY);
  95             BackgroundRequest background1 = new BackgroundRequest(TmfTimeRange.ETERNITY);
  96             trace.sendRequest(background1);
  97             trace.sendRequest(foreground1);
  98             trace.sendRequest(foreground2);
  99             try {
 100                 foreground1.waitForCompletion();
 101                 foreground2.waitForCompletion();
 102                 background1.waitForCompletion();
 103             } catch (InterruptedException e) {
 104                 e.printStackTrace();
 105             }
 106             averageWaitingBackground += background1.getAverageWaitingTime();
 107             averageWaitingForeground1 += foreground1.getAverageWaitingTime();
 108             averageWaitingForeground2 += foreground2.getAverageWaitingTime();
 109         }
 110         pw.print("-- Background : ");
 111         pw.println((averageWaitingBackground / NUM_LOOPS) / NANOSECONDS_IN_MILLISECONDS + " ms");
 112
 113         pw.print("-- First foreground : ");
 114         pw.println((averageWaitingForeground1 / NUM_LOOPS) / NANOSECONDS_IN_MILLISECONDS + " ms");
 115
 116         pw.print("-- Second foreground : ");
 117         pw.println((averageWaitingForeground2 / NUM_LOOPS) / NANOSECONDS_IN_MILLISECONDS + " ms");
 118     }
 119
 120     private static void completedTime() {
 121         long averageCompletedTime1 = 0;
 122         long averageCompletedTime2 = 0;
 123         long averageCompletedTime3 = 0;
 124         long averageCompletedTime4 = 0;
 125         long averageCompletedTime5 = 0;
 126         long averageCompletedTime6 = 0;
 127
 128         pw.println("----- Time to complete request -----");
 129         for (int i = 0; i < NUM_LOOPS; i++) {
 130             try {
 131                 ForegroundRequest foreground1 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 132                 trace.sendRequest(foreground1);
 133                 foreground1.waitForCompletion();
 134                 averageCompletedTime1 += foreground1.getCompletedTime();
 135
 136                 ForegroundRequest foreground2 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 137                 ForegroundRequest foreground3 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 138                 trace.sendRequest(foreground2);
 139                 trace.sendRequest(foreground3);
 140                 foreground2.waitForCompletion();
 141                 foreground3.waitForCompletion();
 142                 averageCompletedTime2 += (foreground2.getCompletedTime() + foreground3.getCompletedTime());
 143
 144                 ForegroundRequest foreground4 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 145                 BackgroundRequest background1 = new BackgroundRequest(TmfTimeRange.ETERNITY);
 146                 trace.sendRequest(foreground4);
 147                 trace.sendRequest(background1);
 148                 foreground4.waitForCompletion();
 149                 background1.waitForCompletion();
 150                 averageCompletedTime3 += (foreground4.getCompletedTime() + background1.getCompletedTime());
 151
 152                 ForegroundRequest foreground5 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 153                 ForegroundRequest foreground6 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 154                 BackgroundRequest background2 = new BackgroundRequest(TmfTimeRange.ETERNITY);
 155                 trace.sendRequest(foreground5);
 156                 trace.sendRequest(foreground6);
 157                 trace.sendRequest(background2);
 158                 foreground5.waitForCompletion();
 159                 foreground6.waitForCompletion();
 160                 background2.waitForCompletion();
 161                 averageCompletedTime4 += (foreground5.getCompletedTime() + foreground6.getCompletedTime() + background2.getCompletedTime());
 162
 163                 ForegroundRequest foreground7 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 164                 ForegroundRequest foreground8 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 165                 ForegroundRequest foreground9 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 166                 BackgroundRequest background3 = new BackgroundRequest(TmfTimeRange.ETERNITY);
 167                 trace.sendRequest(foreground7);
 168                 trace.sendRequest(foreground8);
 169                 trace.sendRequest(foreground9);
 170                 trace.sendRequest(background3);
 171                 foreground7.waitForCompletion();
 172                 foreground8.waitForCompletion();
 173                 foreground9.waitForCompletion();
 174                 background3.waitForCompletion();
 175                 averageCompletedTime5 += (foreground7.getCompletedTime() + foreground8.getCompletedTime() + foreground9.getCompletedTime() + background3.getCompletedTime());
 176
 177                 ForegroundRequest foreground10 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 178                 ForegroundRequest foreground11 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 179                 ForegroundRequest foreground12 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 180                 ForegroundRequest foreground13 = new ForegroundRequest(TmfTimeRange.ETERNITY);
 181                 BackgroundRequest background4 = new BackgroundRequest(TmfTimeRange.ETERNITY);
 182                 trace.sendRequest(foreground10);
 183                 trace.sendRequest(foreground11);
 184                 trace.sendRequest(foreground12);
 185                 trace.sendRequest(foreground13);
 186                 trace.sendRequest(background4);
 187                 foreground10.waitForCompletion();
 188                 foreground11.waitForCompletion();
 189                 foreground12.waitForCompletion();
 190                 foreground13.waitForCompletion();
 191                 background4.waitForCompletion();
 192                 averageCompletedTime6 += (foreground10.getCompletedTime() + foreground11.getCompletedTime() + foreground12.getCompletedTime() + foreground13.getCompletedTime() + background4.getCompletedTime());
 193             } catch (InterruptedException e) {
 194                 e.printStackTrace();
 195             }
 196         }
 197
 198         pw.print("-- Time to complete one request : ");
 199         pw.println((averageCompletedTime1 / NUM_LOOPS) / NANOSECONDS_IN_SECONDS + " s");
 200
 201         pw.print("-- Time to complete 2 requests (2 foreground) : ");
 202         pw.println((averageCompletedTime2 / NUM_LOOPS) / NANOSECONDS_IN_SECONDS + " s");
 203
 204         pw.print("-- Time to complete 2 requests (1 foreground, 1 background) : ");
 205         pw.println((averageCompletedTime3 / NUM_LOOPS) / NANOSECONDS_IN_SECONDS + " s");
 206
 207         pw.print("-- Time to complete 3 requests (2 foreground, 1 background) : ");
 208         pw.println((averageCompletedTime4 / NUM_LOOPS) / NANOSECONDS_IN_SECONDS + " s");
 209
 210         pw.print("-- Time to complete 4 requests (3 foreground, 1 background) : ");
 211         pw.println((averageCompletedTime5 / NUM_LOOPS) / NANOSECONDS_IN_SECONDS + " s");
 212
 213         pw.print("-- Time to complete 5 requests (4 foreground, 1 background) : ");
 214         pw.println((averageCompletedTime6 / NUM_LOOPS) / NANOSECONDS_IN_SECONDS + " s");
 215     }
 216
 217     /**
 218      * The benchmark results
 219      */
 220     public static void benchmarkResults() {
 221         pw.println("---------- Benchmark completed ----------");
 222     }
 223
 224     // ------------------------------------------------------------------------
 225     // Helper methods
 226     // ------------------------------------------------------------------------
 227
 228     private static class BackgroundRequest extends TmfEventRequest {
 229         private long startTime;
 230         private long endTimeLatency = -1;
 231         private long completedTime = 0;
 232         private long waitingTimeStart = 0;
 233         private long waitingTimeEnd = 0;
 234         private long waitingTime = 0;
 235         private int waitingCounter = 0;
 236         private boolean isWaiting = false;
 237
 238         BackgroundRequest(TmfTimeRange timeRange) {
 239             super(trace.getEventType(),
 240                     timeRange,
 241                     0,
 242                     ITmfEventRequest.ALL_DATA,
 243                     ExecutionType.BACKGROUND);
 244             startTime = System.nanoTime();
 245         }
 246
 247         @Override
 248         public void handleData(final ITmfEvent event) {
 249             if (endTimeLatency == -1) {
 250                 endTimeLatency = System.nanoTime();
 251             }
 252             super.handleData(event);
 253             if (lastForegroundRequest == null && lastBackgroundRequest == null) {
 254                 lastBackgroundRequest = this;
 255             }
 256             if (isWaiting) {
 257                 waitingTimeEnd = System.nanoTime();
 258                 waitingTime += waitingTimeEnd - waitingTimeStart;
 259                 ++waitingCounter;
 260                 isWaiting = false;
 261             }
 262             if (lastForegroundRequest != null) {
 263                 lastForegroundRequest.waitingTimeStart = System.nanoTime();
 264                 lastForegroundRequest.isWaiting = true;
 265                 lastForegroundRequest = null;
 266                 lastBackgroundRequest = this;
 267             }
 268             if (lastBackgroundRequest != this) {
 269                 lastBackgroundRequest.waitingTimeStart = System.nanoTime();
 270                 lastBackgroundRequest.isWaiting = true;
 271                 lastBackgroundRequest = this;
 272             }
 273         }
 274
 275         @Override
 276         public void handleCompleted() {
 277             completedTime = System.nanoTime();
 278             super.handleCompleted();
 279         }
 280
 281         public long getCompletedTime() {
 282             return completedTime - startTime;
 283         }
 284
 285         public long getAverageWaitingTime() {
 286             if (waitingCounter == 0) {
 287                 return 0;
 288             }
 289             return waitingTime / waitingCounter;
 290         }
 291     }
 292
 293     private static class ForegroundRequest extends TmfEventRequest {
 294         private long startTime = 0;
 295         private long endTimeLatency = -1;
 296         private long completedTime = 0;
 297         private long waitingTimeStart = 0;
 298         private long waitingTimeEnd = 0;
 299         private long waitingTime = 0;
 300         private int waitingCounter = 0;
 301         private boolean isWaiting = false;
 302
 303         ForegroundRequest(TmfTimeRange timeRange) {
 304             super(trace.getEventType(),
 305                     timeRange,
 306                     0,
 307                     ITmfEventRequest.ALL_DATA,
 308                     ExecutionType.FOREGROUND);
 309             startTime = System.nanoTime();
 310         }
 311
 312         @Override
 313         public void handleData(final ITmfEvent event) {
 314             if (endTimeLatency == -1) {
 315                 endTimeLatency = System.nanoTime();
 316             }
 317             super.handleData(event);
 318             if (lastBackgroundRequest == null && lastForegroundRequest == null) {
 319                 lastForegroundRequest = this;
 320             }
 321             if (isWaiting) {
 322                 waitingTimeEnd = System.nanoTime();
 323                 waitingTime += waitingTimeEnd - waitingTimeStart;
 324                 ++waitingCounter;
 325                 isWaiting = false;
 326             }
 327             if (lastBackgroundRequest != null) {
 328                 lastBackgroundRequest.waitingTimeStart = System.nanoTime();
 329                 lastBackgroundRequest.isWaiting = true;
 330                 lastBackgroundRequest = null;
 331                 lastForegroundRequest = this;
 332             }
 333             if (lastForegroundRequest != this) {
 334                 lastForegroundRequest.waitingTimeStart = System.nanoTime();
 335                 lastForegroundRequest.isWaiting = true;
 336                 lastForegroundRequest = this;
 337             }
 338         }
 339
 340         @Override
 341         public void handleCompleted() {
 342             completedTime = System.nanoTime();
 343             super.handleCompleted();
 344         }
 345
 346         public long getLatency() {
 347             return endTimeLatency - startTime;
 348         }
 349
 350         public long getCompletedTime() {
 351             return completedTime - startTime;
 352         }
 353
 354         public long getAverageWaitingTime() {
 355             if (waitingCounter == 0) {
 356                 return 0;
 357             }
 358             return waitingTime / waitingCounter;
 359         }
 360     }
 361 }