001: package com.commsen.stopwatch;
002:
003: import java.util.Calendar;
004:
005: import junit.framework.TestCase;
006:
007: import org.apache.log4j.Logger;
008:
009: /**
010: * Unit test for Stopwatch.
011: */
012: public abstract class AbstractBaseStopwatchTest extends TestCase {
013:
014: protected final String testsGroup = "tests";
015:
016: int totalCycles = 20;
017: int threads = 100;
018:
019: protected Report report;
020:
021: /**
022: * @see junit.framework.TestCase#setUp()
023: */
024: protected void setUp() throws Exception {
025: System.setProperty(Stopwatch.SYSTEM_PROPERTIES_PREFIX
026: + Stopwatch.PROPERTY_DEBUG, Boolean.toString(true));
027: System.setProperty(Stopwatch.SYSTEM_PROPERTIES_PREFIX
028: + Stopwatch.PROPERTY_ACTIVE, Boolean.toString(true));
029: Stopwatch.setActive(true);
030: }
031:
032: /**
033: * @see junit.framework.TestCase#tearDown()
034: */
035: protected void tearDown() throws Exception {
036: Report[] report = Stopwatch.getAllByGroupReports();
037: System.out
038: .println("-----Stopwatch Groups report------------------");
039: for (int i = 0; i < report.length; i++) {
040: System.out.println(report[i]);
041: }
042: System.out
043: .println("----------------------------------------------");
044:
045: report = Stopwatch.getAllByLabelReports();
046: System.out
047: .println("-----Stopwatch Labels report------------------");
048: for (int i = 0; i < report.length; i++) {
049: System.out.println(report[i]);
050: }
051: System.out
052: .println("----------------------------------------------");
053:
054: report = Stopwatch.getAllReports();
055: System.out
056: .println("-----Stopwatch all report---------------------");
057: for (int i = 0; i < report.length; i++) {
058: System.out.println(report[i]);
059: }
060: System.out
061: .println("----------------------------------------------");
062: }
063:
064: /**
065: * test initialisation
066: */
067: public void testBadInitialization() {
068:
069: // unkown engine
070: System.setProperty(Stopwatch.SYSTEM_PROPERTIES_PREFIX
071: + Stopwatch.PROPERTY_ENGINE, "unkown.engine");
072: Stopwatch.reset();
073: assertFalse(Stopwatch.isActive());
074: Stopwatch.setActive(true);
075: assertFalse(Stopwatch.isActive());
076:
077: // empty engine
078: System.setProperty(Stopwatch.SYSTEM_PROPERTIES_PREFIX
079: + Stopwatch.PROPERTY_ENGINE, "");
080: Stopwatch.reset();
081: Stopwatch.setActive(true);
082: assertTrue(Stopwatch.isActive());
083:
084: // unkown storage
085: System.setProperty(Stopwatch.SYSTEM_PROPERTIES_PREFIX
086: + Stopwatch.PROPERTY_STORAGE, "unkown.storage");
087: Stopwatch.reset();
088: assertFalse(Stopwatch.isActive());
089: Stopwatch.setActive(true);
090: assertFalse(Stopwatch.isActive());
091:
092: // unkown storage
093: System.setProperty(Stopwatch.SYSTEM_PROPERTIES_PREFIX
094: + Stopwatch.PROPERTY_STORAGE, "");
095: Stopwatch.reset();
096: Stopwatch.setActive(true);
097: assertTrue(Stopwatch.isActive());
098:
099: }
100:
101: /**
102: * test groups and labels
103: */
104: public void testGroupAndLabel() {
105: getLogger().info(" === test groups and labels ===");
106: String[] groups = { "g1", "g2", "g3" };
107: String[] labels = { "l1", "l2", "l3", "l4", "l5" };
108:
109: for (int count = 0; count < totalCycles; count++) {
110: for (int g = 0; g < groups.length; g++) {
111: for (int l = 0; l < labels.length; l++) {
112: long id = Stopwatch.start(groups[g], labels[l]);
113: Stopwatch.stop(id);
114: }
115: }
116: }
117:
118: ifThreadedModeWaitFor(groups.length * labels.length);
119:
120: Report[] all = Stopwatch.getAllReports();
121: assertEquals(groups.length * labels.length, all.length);
122:
123: // check that for any group there are as many reports as defined lables
124: for (int g = 0; g < groups.length; g++) {
125: Report[] reports = Stopwatch.getGroupReports(groups[g]);
126: assertEquals(labels.length, reports.length);
127: }
128:
129: // check that for any label there are as many reports as defined groups
130: for (int l = 0; l < labels.length; l++) {
131: Report[] reports = Stopwatch.getLabelReports(labels[l]);
132: assertEquals(groups.length, reports.length);
133: }
134:
135: Report[] allByGroup = Stopwatch.getAllByGroupReports();
136: assertEquals(groups.length, allByGroup.length);
137:
138: Report[] allByLabel = Stopwatch.getAllByLabelReports();
139: assertEquals(labels.length, allByLabel.length);
140:
141: for (int g = 0; g < allByGroup.length; g++) {
142: Report current = allByGroup[g];
143: Report[] groupReports = Stopwatch.getGroupReports(current
144: .getGroup());
145: long counts = 0;
146: double min = 0, max = 0;
147: for (int c = 0; c < groupReports.length; c++) {
148: counts += groupReports[c].getCount();
149: if (groupReports[c].getMinTime() < min)
150: min = groupReports[c].getMinTime();
151: if (groupReports[c].getMaxTime() > max)
152: max = groupReports[c].getMaxTime();
153: }
154: assertEquals(counts, current.getCount());
155: assertEquals(min, current.getMinTime(), 0);
156: assertEquals(max, current.getMaxTime(), 0);
157: }
158:
159: for (int l = 0; l < allByLabel.length; l++) {
160: Report current = allByLabel[l];
161: Report[] labelReports = Stopwatch.getLabelReports(current
162: .getLabel());
163: long counts = 0;
164: double min = 0, max = 0;
165: for (int c = 0; c < labelReports.length; c++) {
166: counts += labelReports[c].getCount();
167: if (labelReports[c].getMinTime() < min)
168: min = labelReports[c].getMinTime();
169: if (labelReports[c].getMaxTime() > max)
170: max = labelReports[c].getMaxTime();
171: }
172: assertEquals(current.getCount(), counts);
173: assertEquals(current.getMinTime(), min, 0);
174: assertEquals(current.getMaxTime(), max, 0);
175: }
176:
177: }
178:
179: /**
180: * Count test
181: */
182: public void testCount() {
183: getLogger().info(" === test count ===");
184: String testLabel = "testCount";
185:
186: for (int count = 0; count < totalCycles; count++) {
187: long id = Stopwatch.start(testsGroup, testLabel);
188: Stopwatch.stop(id);
189: }
190:
191: ifThreadedModeWaitFor(totalCycles);
192: report = Stopwatch.getSingleReport(testsGroup, testLabel);
193: assertEquals(totalCycles, report.getCount());
194:
195: }
196:
197: /**
198: * test bad usage
199: *
200: */
201: public void testBadUsage() {
202: getLogger().info(" === test bad usage scenarios ===");
203: String testLabel = "testBadUsage";
204:
205: // test started and stopped many times
206: long[] ids = new long[totalCycles];
207: for (int count = 0; count < totalCycles; count++) {
208: ids[count] = Stopwatch.start(testsGroup, testLabel);
209: for (int i = 0; i <= count; i++) {
210: Stopwatch.stop(ids[i]);
211: }
212: }
213:
214: ifThreadedModeWaitFor(totalCycles);
215: report = Stopwatch.getSingleReport(testsGroup, testLabel);
216: assertEquals(totalCycles, report.getCount());
217:
218: // test started and never stopped
219: Stopwatch.reset();
220: for (int count = 0; count < totalCycles; count++) {
221: Stopwatch.start(testsGroup, testLabel);
222: }
223:
224: ifThreadedModeWaitFor(totalCycles);
225: report = Stopwatch.getSingleReport(testsGroup, testLabel);
226: assertNull(report);
227: }
228:
229: /**
230: * Measure zero length operation
231: *
232: */
233: public void testZeroTiming() {
234: getLogger().info(" === test zero timings ===");
235: String testLabel = "zero timing";
236:
237: for (int i = 0; i < totalCycles; i++) {
238: long id = Stopwatch.start(testsGroup, testLabel);
239: Stopwatch.stop(id);
240: }
241:
242: ifThreadedModeWaitFor(totalCycles);
243: report = Stopwatch.getSingleReport(testsGroup, testLabel);
244:
245: assertTrue(report.getAverageTime() == 0);
246:
247: }
248:
249: /**
250: * Timings test
251: *
252: */
253: public void testTiming() {
254: getLogger().info(" === test correct timings ===");
255: String testLabel = "timing";
256: int minWait = 50;
257: int maxWait = 200;
258:
259: for (int i = 0; i < 100; i++) {
260: long id = Stopwatch.start(testsGroup, testLabel);
261: try {
262: Thread
263: .sleep((long) (Math.random() * (maxWait - minWait))
264: + minWait);
265: } catch (InterruptedException e) {
266: }
267: Stopwatch.stop(id);
268: }
269:
270: report = Stopwatch.getSingleReport(testsGroup, testLabel);
271:
272: int offset = 5; // sleep is approximate so we'll be approximate too
273: assertTrue(report.getMinTime() > (minWait - offset));
274: assertTrue(report.getMaxTime() > (maxWait - offset));
275: assertTrue(report.getAverageTime() > minWait);
276: assertTrue(report.getAverageTime() < maxWait);
277: assertEquals(report.getTotalTime() / report.getCount(), report
278: .getAverageTime(), 1);
279:
280: }
281:
282: /**
283: * Skip test
284: *
285: */
286: public void testSkip() {
287: getLogger().info(" === test skipping measurments ===");
288: String testLabel = "testSkip";
289:
290: for (int count = 0; count < totalCycles; count++) {
291: long id = Stopwatch.start(testsGroup, testLabel);
292: try {
293: if (count % 2 == 0)
294: throw new Exception();
295: } catch (Exception e) {
296: Stopwatch.skip(id);
297: } finally {
298: Stopwatch.stop(id);
299: }
300: }
301:
302: ifThreadedModeWaitFor(totalCycles);
303: report = Stopwatch.getSingleReport(testsGroup, testLabel);
304: assertEquals(totalCycles / 2, report.getCount()); //half should be skipped
305: }
306:
307: /**
308: * Recursion test
309: *
310: */
311: public void testRecursion() {
312: getLogger().info(" === test recursion ===");
313: String testLabel = "recursion";
314:
315: callSelf(testsGroup, testLabel, totalCycles);
316:
317: // if threaded give 1ms per record to complete
318: ifThreadedModeWaitFor(totalCycles);
319: report = Stopwatch.getSingleReport(testsGroup, testLabel);
320: assertNotNull(report);
321:
322: }
323:
324: private void callSelf(String group, String label, int left) {
325: if (left == 0) {
326: System.out.println("");
327: return;
328: }
329: long id = Stopwatch.start(group, label);
330: System.out.print(left + " ");
331: callSelf(group, label, left - 1);
332: Stopwatch.stop(id);
333: }
334:
335: /**
336: *
337: *
338: */
339: public void testMultithreaded() {
340: getLogger().info(" === test multithreaded environment ===");
341: Worker testWorker = new Worker();
342:
343: for (int i = 0; i < threads; i++) {
344: Thread thread = new Thread(testWorker, "Th" + i);
345: thread.start();
346: // wait 10 ms before starting next one
347: try {
348: Thread.sleep(10);
349: } catch (InterruptedException e) {
350: }
351: }
352:
353: // wait for threads
354: while (testWorker.threads > 0) {
355: System.out.println("Waiting for " + testWorker.threads
356: + " threads!");
357: try {
358: Thread.sleep(1000);
359: } catch (InterruptedException e) {
360: }
361: }
362:
363: Report[] reports = Stopwatch.getAllReports();
364: for (int i = 0; i < reports.length; i++) {
365: assertEquals(threads * totalCycles, reports[i].getCount());
366: }
367: }
368:
369: /**
370: *
371: *
372: */
373: public void testLoad() {
374: String label = "testLoad";
375: for (int count = 0; count < totalCycles; count++) {
376: long id = Stopwatch.start(testsGroup, label);
377: try {
378: Thread.sleep(500);
379: } catch (InterruptedException e) {
380: }
381: Stopwatch.stop(id);
382: }
383:
384: ifThreadedModeWaitFor(totalCycles);
385: long[] load1 = Stopwatch.getLoad(Calendar.SECOND, 10);
386: long[] load2 = Stopwatch.getLoad(testsGroup, label,
387: Calendar.SECOND, 10);
388: long[] load3 = Stopwatch.getGroupLoad(testsGroup,
389: Calendar.SECOND, 10);
390: long[] load4 = Stopwatch.getLabelLoad(label, Calendar.SECOND,
391: 10);
392:
393: assertTrue(load1.length > 0);
394: assertTrue(load2.length > 0);
395: assertTrue(load3.length > 0);
396: assertTrue(load4.length > 0);
397:
398: long max = 0;
399: for (int i = 0; i < load1.length; i++) {
400: if (max < load1[i])
401: max = load1[i];
402: System.out.print(load1[i] + " ");
403: }
404:
405: System.out.println("");
406: }
407:
408: /**
409: *
410: * @param records
411: */
412: void ifThreadedModeWaitFor(int records) {
413: int millisPerRecord = 10;
414: if (Stopwatch.getPersistenceMode().equals("THREAD"))
415: System.out.println("Engine is in THRED mode! Will wait "
416: + records * millisPerRecord
417: + " ms for thread co complete!");
418: try {
419: Thread.sleep(records * millisPerRecord);
420: } catch (InterruptedException e) {
421: }
422: }
423:
424: /**
425: * Simple worker for multithreaded tests
426: *
427: * @author Milen Dyankov
428: */
429: class Worker implements Runnable {
430:
431: public int threads = 0;
432:
433: public void measuredMethod(int min, int max) {
434: long sw = Stopwatch.start(testsGroup, min + "-" + max);
435: long sleep = (long) (Math.random() * (max - min)) + min;
436: try {
437: Thread.sleep(sleep);
438: } catch (InterruptedException e) {
439: }
440: Stopwatch.stop(sw);
441: };
442:
443: // public void measuredMethod2() {
444: // long sw = Stopwatch.start(testsGroup, "threadTest2");
445: // long sleep = (long) (Math.random() * 100) + 500;
446: // try {
447: // Thread.sleep(sleep);
448: // } catch (InterruptedException e) {
449: // }
450: // Stopwatch.stop(sw);
451: // };
452:
453: public void run() {
454: threads++;
455: for (int i = 0; i < totalCycles; i++) {
456: measuredMethod(50, 100);
457: measuredMethod(50, 200);
458: }
459: threads--;
460: }
461:
462: }
463:
464: public abstract Logger getLogger();
465:
466: }
|