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