001: /*
002: * Licensed to the Apache Software Foundation (ASF) under one or more
003: * contributor license agreements. See the NOTICE file distributed with
004: * this work for additional information regarding copyright ownership.
005: * The ASF licenses this file to You under the Apache License, Version 2.0
006: * (the "License"); you may not use this file except in compliance with
007: * the License. You may obtain a copy of the License at
008: *
009: * http://www.apache.org/licenses/LICENSE-2.0
010: *
011: * Unless required by applicable law or agreed to in writing, software
012: * distributed under the License is distributed on an "AS IS" BASIS,
013: * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
014: * See the License for the specific language governing permissions and
015: * limitations under the License.
016: *
017: */
018:
019: package org.apache.jmeter.reporters;
020:
021: import java.io.Serializable;
022: import java.text.DecimalFormat;
023: import java.util.Hashtable;
024:
025: import org.apache.jmeter.engine.event.LoopIterationEvent;
026: import org.apache.jmeter.samplers.Clearable;
027: import org.apache.jmeter.samplers.SampleEvent;
028: import org.apache.jmeter.samplers.SampleListener;
029: import org.apache.jmeter.samplers.SampleResult;
030: import org.apache.jmeter.testelement.AbstractTestElement;
031: import org.apache.jmeter.testelement.TestListener;
032: import org.apache.jmeter.util.JMeterUtils;
033: import org.apache.jmeter.visualizers.RunningSample;
034: import org.apache.jorphan.logging.LoggingManager;
035: import org.apache.jorphan.util.JOrphanUtils;
036: import org.apache.log.Logger;
037:
038: /**
039: * Generate a summary of the test run so far to the log file and/or standard
040: * output. Both running and differential totals are shown. Output is generated
041: * every n seconds (default 3 minutes) on the appropriate time boundary, so that
042: * multiple test runs on the same time will be synchronised.
043: *
044: * This is mainly intended for batch (non-GUI) runs
045: *
046: * Note that the RunningSample start and end times relate to the samples,
047: * not the reporting interval.
048: *
049: * Since the first sample in a delta is likely to have started in the previous reporting interval,
050: * this means that the delta interval is likely to be longer than the reporting interval.
051: *
052: * Also, the sum of the delta intervals will be larger than the overall elapsed time.
053: *
054: */
055: public class Summariser extends AbstractTestElement implements
056: Serializable, SampleListener, TestListener, Clearable {
057: private static final Logger log = LoggingManager
058: .getLoggerForClass();
059:
060: /** interval between summaries (in seconds) default 3 minutes */
061: private static final long INTERVAL = JMeterUtils.getPropDefault(
062: "summariser.interval", 3 * 60); //$NON-NLS-1$
063:
064: /** Write messages to log file ? */
065: private static final boolean TOLOG = JMeterUtils.getPropDefault(
066: "summariser.log", true); //$NON-NLS-1$
067:
068: /** Write messages to System.out ? */
069: private static final boolean TOOUT = JMeterUtils.getPropDefault(
070: "summariser.out", true); //$NON-NLS-1$
071:
072: /**
073: * Summariser elements are cloned for each thread in each group; this Map is
074: * used to allow them to share the same statistics. The key is the
075: * Summariser name, so all Summarisers with the same name will use the same
076: * accumulators.
077: */
078: private static Hashtable accumulators = new Hashtable();
079:
080: /*
081: * Constructor is initially called once for each occurrence in the test plan.
082: * For GUI, several more instances are created.
083: * Then clear is called at start of test.
084: * Called several times during test startup.
085: * The name will not necessarily have been set at this point.
086: */
087: public Summariser() {
088: super ();
089: // log.debug(Thread.currentThread().getName());
090: // System.out.println(">> "+me+" "+this.getName()+"
091: // "+Thread.currentThread().getName());
092: }
093:
094: /**
095: * Constructor for use during startup (intended for non-GUI use)
096: *
097: * @param name of summariser
098: */
099: public Summariser(String name) {
100: this ();
101: setName(name);
102: }
103:
104: public void clearData() {
105: // not used
106: }
107:
108: /*
109: * Contains the items needed to collect stats for a summariser
110: *
111: */
112: private static class Totals {
113:
114: /** Time of last summary (to prevent double reporting) */
115: private long last = 0;// set to -1 by TestEnded to prevent double
116: // reporting
117:
118: private RunningSample delta = new RunningSample("DELTA", 0);
119:
120: private RunningSample total = new RunningSample("TOTAL", 0);
121:
122: private void clear() {
123: delta.clear();
124: total.clear();
125: last = 0;
126: }
127:
128: /**
129: * Add the delta values to the total values and clear the delta
130: */
131: private synchronized void moveDelta() {
132: total.addSample(delta);
133: delta.clear();
134: }
135: }
136:
137: /*
138: * Cached copy of Totals for this instance.
139: * The variables do not need to be synchronised,
140: * as they are not shared between threads
141: */
142: transient private Totals myTotals = null;
143:
144: transient private String myName;
145:
146: /*
147: * Ensure that a report is not skipped if we are slightly late in checking
148: * the time.
149: */
150: private static final int INTERVAL_WINDOW = 5; // in seconds
151:
152: /**
153: * Accumulates the sample in two SampleResult objects - one for running
154: * totals, and the other for deltas.
155: *
156: * @see org.apache.jmeter.samplers.SampleListener#sampleOccurred(org.apache.jmeter.samplers.SampleEvent)
157: */
158: public void sampleOccurred(SampleEvent e) {
159: SampleResult s = e.getResult();
160:
161: // System.out.println("SO "+me+this.getName()+"
162: // "+Thread.currentThread().getName()
163: // +" "+s.getSampleLabel());
164:
165: if (myName == null)
166: myName = getName();
167:
168: if (myTotals == null) {
169: synchronized (accumulators) {
170: myTotals = (Totals) accumulators.get(myName);
171: }
172: }
173:
174: if (s != null) {
175: myTotals.delta.addSample(s);
176: }
177:
178: long now = System.currentTimeMillis() / 1000;// in seconds
179:
180: RunningSample myDelta = null;
181: RunningSample myTotal = null;
182: boolean reportNow = false;
183:
184: /*
185: * Have we reached the reporting boundary?
186: * Need to allow for a margin of error, otherwise can miss the slot.
187: * Also need to check we've not hit the window already
188: */
189: synchronized (myTotals) {
190: if ((now > myTotals.last + INTERVAL_WINDOW)
191: && (now % INTERVAL <= INTERVAL_WINDOW)) {
192: reportNow = true;
193:
194: // copy the data to minimise the synch time
195: myDelta = new RunningSample(myTotals.delta);
196: myTotals.moveDelta();
197: myTotal = new RunningSample(myTotals.total);
198:
199: myTotals.last = now;
200: }
201: }
202: if (reportNow) {
203: String str;
204: str = format(myDelta, "+");
205: if (TOLOG) {
206: log.info(str);
207: }
208: if (TOOUT) {
209: System.out.println(str);
210: }
211:
212: // Only if we have updated them
213: if (myTotal.getNumSamples() != myDelta.getNumSamples()) {
214: str = format(myTotal, "=");
215: if (TOLOG) {
216: log.info(str);
217: }
218: if (TOOUT) {
219: System.out.println(str);
220: }
221: }
222: }
223: }
224:
225: private static StringBuffer longToSb(StringBuffer sb, long l,
226: int len) {
227: sb.setLength(0);
228: sb.append(l);
229: return JOrphanUtils.rightAlign(sb, len);
230: }
231:
232: private static DecimalFormat dfDouble = new DecimalFormat("#0.0");
233:
234: private static StringBuffer doubleToSb(StringBuffer sb, double d,
235: int len, int frac) {
236: sb.setLength(0);
237: dfDouble.setMinimumFractionDigits(frac);
238: dfDouble.setMaximumFractionDigits(frac);
239: sb.append(dfDouble.format(d));
240: return JOrphanUtils.rightAlign(sb, len);
241: }
242:
243: /**
244: * @param myTotal
245: * @param string
246: * @return
247: */
248: private String format(RunningSample s, String type) {
249: StringBuffer tmp = new StringBuffer(20); // for intermediate use
250: StringBuffer sb = new StringBuffer(100); // output line buffer
251: sb.append(myName);
252: sb.append(" ");
253: sb.append(type);
254: sb.append(" ");
255: sb.append(longToSb(tmp, s.getNumSamples(), 5));
256: sb.append(" in ");
257: long elapsed = s.getElapsed();
258: sb.append(doubleToSb(tmp, elapsed / 1000.0, 5, 1));
259: sb.append("s = ");
260: if (elapsed > 0) {
261: sb.append(doubleToSb(tmp, s.getRate(), 6, 1));
262: } else {
263: sb.append("******");// Rate is effectively infinite
264: }
265: sb.append("/s Avg: ");
266: sb.append(longToSb(tmp, s.getAverage(), 5));
267: sb.append(" Min: ");
268: sb.append(longToSb(tmp, s.getMin(), 5));
269: sb.append(" Max: ");
270: sb.append(longToSb(tmp, s.getMax(), 5));
271: sb.append(" Err: ");
272: sb.append(longToSb(tmp, s.getErrorCount(), 5));
273: sb.append(" (");
274: sb.append(s.getErrorPercentageString());
275: sb.append(")");
276: return sb.toString();
277: }
278:
279: /*
280: * (non-Javadoc)
281: *
282: * @see org.apache.jmeter.samplers.SampleListener#sampleStarted(org.apache.jmeter.samplers.SampleEvent)
283: */
284: public void sampleStarted(SampleEvent e) {
285: // not used
286: }
287:
288: /*
289: * (non-Javadoc)
290: *
291: * @see org.apache.jmeter.samplers.SampleListener#sampleStopped(org.apache.jmeter.samplers.SampleEvent)
292: */
293: public void sampleStopped(SampleEvent e) {
294: // not used
295: }
296:
297: /*
298: * (non-Javadoc)
299: *
300: * @see org.apache.jmeter.testelement.TestListener#testStarted()
301: */
302: public void testStarted() {
303: testStarted("local");
304: }
305:
306: /*
307: * (non-Javadoc)
308: *
309: * @see org.apache.jmeter.testelement.TestListener#testEnded()
310: */
311: public void testEnded() {
312: testEnded("local");
313:
314: }
315:
316: /*
317: * (non-Javadoc)
318: *
319: * @see org.apache.jmeter.testelement.TestListener#testStarted(java.lang.String)
320: */
321: public void testStarted(String host) {
322: myName = this .getName();
323:
324: // Hashtable is synchronised, but there could be more than one Summariser
325: // with the same name, so we need to synchronise.
326: synchronized (accumulators) {
327: Totals tots = (Totals) accumulators.get(myName);
328: if (tots != null) {// This can be null (before first sample)
329: tots.clear();
330: } else {
331: // System.out.println("Creating totals for "+myName);
332: tots = new Totals();
333: accumulators.put(myName, tots);
334: }
335: }
336: }
337:
338: /*
339: * (non-Javadoc) Can be called more than once with the same name, so need to
340: * synch. However, there is no need to create copies, to shorten the synch
341: * zone, as timing is not critical at the end of the test.
342: *
343: * @see org.apache.jmeter.testelement.TestListener#testEnded(java.lang.String)
344: */
345: public void testEnded(String host) {
346: // System.out.println("TE "+me+this.getName()+"
347: // "+Thread.currentThread().getName());
348: synchronized (accumulators) {
349: Totals t = (Totals) accumulators.get(myName);
350: if (t.last != -1) {
351: String str;
352: if (t.total.getNumSamples() != 0) {// Only print delta if different
353: // from total
354: str = format(t.delta, "+");
355: if (TOLOG)
356: log.info(str);
357: if (TOOUT)
358: System.out.println(str);
359: }
360: t.moveDelta();
361: str = format(t.total, "=");
362: if (TOLOG)
363: log.info(str);
364: if (TOOUT)
365: System.out.println(str);
366: t.last = -1;
367: }
368: }
369: }
370:
371: /*
372: * (non-Javadoc)
373: *
374: * @see org.apache.jmeter.testelement.TestListener#testIterationStart(org.apache.jmeter.engine.event.LoopIterationEvent)
375: */
376: public void testIterationStart(LoopIterationEvent event) {
377: // not used
378: }
379:
380: }
|