001: /*
002: * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS HEADER.
003: *
004: * Copyright 1997-2007 Sun Microsystems, Inc. All rights reserved.
005: *
006: * The contents of this file are subject to the terms of either the GNU
007: * General Public License Version 2 only ("GPL") or the Common
008: * Development and Distribution License("CDDL") (collectively, the
009: * "License"). You may not use this file except in compliance with the
010: * License. You can obtain a copy of the License at
011: * http://www.netbeans.org/cddl-gplv2.html
012: * or nbbuild/licenses/CDDL-GPL-2-CP. See the License for the
013: * specific language governing permissions and limitations under the
014: * License. When distributing the software, include this License Header
015: * Notice in each file and include the License file at
016: * nbbuild/licenses/CDDL-GPL-2-CP. Sun designates this
017: * particular file as subject to the "Classpath" exception as provided
018: * by Sun in the GPL Version 2 section of the License file that
019: * accompanied this code. If applicable, add the following below the
020: * License Header, with the fields enclosed by brackets [] replaced by
021: * your own identifying information:
022: * "Portions Copyrighted [year] [name of copyright owner]"
023: *
024: * Contributor(s):
025: *
026: * The Original Software is NetBeans. The Initial Developer of the Original
027: * Software is Sun Microsystems, Inc. Portions Copyright 1997-2006 Sun
028: * Microsystems, Inc. All Rights Reserved.
029: *
030: * If you wish your version of this file to be governed by only the CDDL
031: * or only the GPL Version 2, indicate your decision by adding
032: * "[Contributor] elects to include this software in this distribution
033: * under the [CDDL or GPL Version 2] license." If you do not indicate a
034: * single choice of license, a recipient has the option to distribute
035: * your version of this file under either the CDDL, the GPL Version 2 or
036: * to extend the choice of license to its licensees as provided above.
037: * However, if you add GPL Version 2 code and therefore, elected the GPL
038: * Version 2 license, then the option applies only if the new code is
039: * made subject to such option by the copyright holder.
040: */
041:
042: package org.netbeans.junit;
043:
044: import java.io.ByteArrayInputStream;
045: import java.io.ByteArrayOutputStream;
046: import java.io.IOException;
047: import java.io.PrintStream;
048: import java.lang.ref.Reference;
049: import java.lang.ref.WeakReference;
050: import java.lang.reflect.InvocationTargetException;
051: import java.text.MessageFormat;
052: import java.util.ArrayList;
053: import java.util.Collections;
054: import java.util.List;
055: import java.util.Map;
056: import java.util.MissingResourceException;
057: import java.util.ResourceBundle;
058: import java.util.WeakHashMap;
059: import java.util.logging.Handler;
060: import java.util.logging.Level;
061: import java.util.logging.LogManager;
062: import java.util.logging.LogRecord;
063: import java.util.logging.Logger;
064: import junit.framework.Assert;
065: import junit.framework.AssertionFailedError;
066:
067: /** Collects log messages.
068: *
069: * @author Jaroslav Tulach
070: */
071: public final class Log extends Handler {
072: /** the test that is currently running */
073: private static NbTestCase current;
074: /** last 40Kb of collected error messages */
075: private static final StringBuffer messages = new StringBuffer();
076: /** initial length of messages */
077: private static int initialMessages;
078: /** stream to log to */
079: private Reference<PrintStream> log;
080: /** logger we are assigned to */
081: private Logger logger;
082:
083: /** Creates a new instance of Log */
084: public Log() {
085: }
086:
087: /** Creates handler with assigned logger
088: */
089: private Log(Logger l, PrintStream ps) {
090: log = new WeakReference<PrintStream>(ps);
091: logger = l;
092: }
093:
094: /** Enables logging for given logger name and given severity.
095: * Everything logged to the object is going to go to the returned
096: * CharSequence object which can be used to check the content or
097: * converted <code>toString</code>.
098: * <p>
099: * The logging stops when the returned object is garbage collected.
100: *
101: * @param loggerName the name to capture logging for
102: * @param level the level of details one wants to get
103: * @return character sequence which can be check or converted to string
104: * @since 1.27
105: */
106: public static CharSequence enable(String loggerName, Level level) {
107: class MyPs extends PrintStream implements CharSequence {
108: private ByteArrayOutputStream os;
109:
110: public MyPs() {
111: this (new ByteArrayOutputStream());
112: }
113:
114: private MyPs(ByteArrayOutputStream arr) {
115: super (arr);
116: os = arr;
117: }
118:
119: public int length() {
120: return toString().length();
121: }
122:
123: public char charAt(int index) {
124: return toString().charAt(index);
125: }
126:
127: public CharSequence subSequence(int start, int end) {
128: return toString().subSequence(start, end);
129: }
130:
131: public String toString() {
132: return os.toString();
133: }
134: }
135:
136: Logger l = Logger.getLogger(loggerName);
137: if (l.getLevel() == null
138: || l.getLevel().intValue() > level.intValue()) {
139: l.setLevel(level);
140: }
141: MyPs ps = new MyPs();
142: Log log = new Log(l, ps);
143: log.setLevel(level);
144: l.addHandler(log);
145: return ps;
146: }
147:
148: /**
149: * Can emulate the execution flow of multiple threads in a deterministic
150: * way so it is easy to emulate race conditions or deadlocks just with
151: * the use of additional log messages inserted into the code.
152: * <p>
153: * The best example showing usage of this method is real life test.
154: * Read <a href="http://www.netbeans.org/source/browse/xtest/nbjunit/test/unit/src/org/netbeans/junit/FlowControlTest.java">FlowControlTest.java</a> to know everything
155: * about the expected usage of this method.
156: * <p>
157: * The method does listen on output send to a logger <code>listenTo</code>
158: * by various threads and either suspends them or wake them up trying
159: * as best as it can to mimic the log output described in <code>order</code>.
160: * Of course, this may not always be possible, so there is the <code>timeout</code>
161: * value which specifies the maximum time a thread can be suspended while
162: * waiting for a single message. The information about the internal behaviour
163: * of the controlFlow method can be send to <code>reportTo</code> logger,
164: * if provided, so in case of failure one can analyse what went wrong.
165: * <p>
166: * The format of the order is a set of lines like:
167: * <pre>
168: * THREAD:name_of_the_thread MSG:message_to_expect
169: * </pre>
170: * which define the order saying that at this time a thread with a given name
171: * is expected to send given message. Both the name of the thread and
172: * the message are regular expressions so one can shorten them by using <q>.*</q>
173: * or any other trick. Btw. the format of the <code>order</code> is similar
174: * to the one logged by the {@link Log#enable} or {@link NbTestCase#logLevel} methods,
175: * so when one gets a test failure with enabled logging,
176: * it is enough to just delete the unnecessary messages, replace too specific
177: * texts like <code>@574904</code> with <code>.*</code> and the order is
178: * ready for use.
179: *
180: * @param listenTo the logger to listen to and guide the execution according to messages sent to it
181: * @param reportTo the logger to report internal state to or <code>null</code> if the logging is not needed
182: * @param order the string describing the expected execution order of threads
183: * @param timeout the maximal wait time of each thread on given message, zero if the waiting shall be infinite
184: *
185: * @author Jaroslav Tulach, invented during year 2005
186: * @since 1.28
187: */
188: public static void controlFlow(Logger listenTo, Logger reportTo,
189: String order, int timeout) {
190: ControlFlow
191: .registerSwitches(listenTo, reportTo, order, timeout);
192: }
193:
194: /** Starts to listen on given log and collect parameters of messages that
195: * were send to it. This is supposed to be called at the begining of a test,
196: * to get messages from the programs that use
197: * <a href="http://wiki.netbeans.org/wiki/view/FitnessViaTimersCounters">timers/counters</a>
198: * infrastructure. At the end one should call {@link assertInstances}.
199: *
200: *
201: * @param log logger to listen on, if null, it uses the standard timers/counters one
202: * @param msg name of messages to collect, if null, all messages will be recorded
203: * @param level level of messages to record
204: * @since 1.44
205: */
206: public static void enableInstances(Logger log, String msg,
207: Level level) {
208: if (log == null) {
209: log = Logger.getLogger("TIMER"); // NOI18N
210: }
211:
212: log.addHandler(new InstancesHandler(msg, level));
213:
214: if (log.getLevel() == null
215: || log.getLevel().intValue() > level.intValue()) {
216: log.setLevel(level);
217: }
218: }
219:
220: /** Assert to verify that all collected instances via {@link enableInstances}
221: * can disappear. Uses {@link NbTestCase#assertGC} on each of them.
222: *
223: * @param msg message to display in case of potential failure
224: */
225: public static void assertInstances(String msg) {
226: InstancesHandler.assertGC(msg);
227: }
228:
229: static void configure(Level lev, NbTestCase current) {
230: String c = "handlers=" + Log.class.getName() + "\n" + ".level="
231: + lev.intValue() + "\n";
232:
233: ByteArrayInputStream is = new ByteArrayInputStream(c.getBytes());
234: try {
235: LogManager.getLogManager().readConfiguration(is);
236: } catch (IOException ex) {
237: // exception
238: ex.printStackTrace();
239: }
240:
241: Log.current = current;
242: Log.messages.setLength(0);
243: Log.messages.append("Starting test ");
244: Log.messages.append(current.getName());
245: Log.messages.append('\n');
246: Log.initialMessages = Log.messages.length();
247: }
248:
249: private PrintStream getLog(LogRecord record) {
250: if (log != null) {
251: PrintStream ps = log.get();
252: if (ps == null) {
253: // gc => remove the handler
254: logger.removeHandler(this );
255: }
256:
257: return ps == null ? System.err : ps;
258: }
259:
260: NbTestCase c = current;
261: return c == null ? System.err : c.getLog();
262: }
263:
264: public void publish(LogRecord record) {
265: StringBuffer sb = new StringBuffer();
266: sb.append('[');
267: sb.append(record.getLoggerName());
268: sb.append("] THREAD: ");
269: sb.append(Thread.currentThread().getName());
270: sb.append(" MSG: ");
271: String msg = record.getMessage();
272: ResourceBundle b = record.getResourceBundle();
273: if (b != null) {
274: try {
275: msg = b.getString(msg);
276: } catch (MissingResourceException ex) {
277: // ignore
278: }
279: }
280:
281: if (msg != null && record.getParameters() != null) {
282: msg = MessageFormat.format(msg, record.getParameters());
283: }
284: sb.append(msg);
285:
286: Throwable t = record.getThrown();
287: if (t != null) {
288: for (StackTraceElement s : t.getStackTrace()) {
289: sb.append("\n ").append(s.toString());
290: }
291: }
292:
293: getLog(record).println(sb.toString());
294:
295: messages.append(sb.toString());
296: messages.append('\n');
297:
298: if (messages.length() > 40000) {
299: messages.delete(0, 20000);
300: }
301:
302: if (record.getThrown() != null) {
303: record.getThrown().printStackTrace(getLog(record));
304: }
305: }
306:
307: public void flush() {
308: }
309:
310: public void close() {
311: }
312:
313: static Throwable wrapWithMessages(Throwable ex) {
314: if (messages.length() == initialMessages) {
315: // no wrapping
316: return ex;
317: }
318:
319: if (ex instanceof AssertionFailedError) {
320: AssertionFailedError ne = new AssertionFailedError(ex
321: .getMessage()
322: + " Log:\n" + messages);
323: ne.setStackTrace(ex.getStackTrace());
324: return ne;
325: }
326:
327: if (ex instanceof IOException) {//#66208
328: IOException ne = new IOException(ex.getMessage()
329: + " Log:\n" + messages);
330: ne.setStackTrace(ex.getStackTrace());
331: return ne;
332: }
333:
334: if (ex instanceof Exception) {
335: return new InvocationTargetException(ex, ex.getMessage()
336: + " Log:\n" + messages);
337: }
338:
339: return ex;
340: }
341:
342: private static class InstancesHandler extends Handler {
343: private static final Map<Object, String> instances = Collections
344: .synchronizedMap(new WeakHashMap<Object, String>());
345: private static int cnt;
346:
347: private final String msg;
348:
349: public InstancesHandler(String msg, Level level) {
350: setLevel(level);
351: this .msg = msg;
352: }
353:
354: @Override
355: public void publish(LogRecord record) {
356: Object[] param = record.getParameters();
357: if (param == null) {
358: return;
359: }
360: if (msg != null && !msg.equals(record.getMessage())) {
361: return;
362: }
363: cnt++;
364: for (Object o : param) {
365: instances.put(o, record.getMessage());
366: }
367: }
368:
369: @Override
370: public void flush() {
371: }
372:
373: @Override
374: public void close() throws SecurityException {
375: }
376:
377: public static void assertGC(String msg) {
378: if (cnt == 0) {
379: Assert.fail("No objects to track reported: " + cnt);
380: }
381: // start from scratch
382: cnt = 0;
383:
384: AssertionFailedError t = null;
385:
386: List<Reference> refs = new ArrayList<Reference>();
387: List<String> txts = new ArrayList<String>();
388: int count = 0;
389: synchronized (instances) {
390: for (Map.Entry<Object, String> entry : instances
391: .entrySet()) {
392: refs.add(new WeakReference<Object>(entry.getKey()));
393: txts.add(entry.getValue());
394: count++;
395: }
396: instances.clear();
397: }
398:
399: for (int i = 0; i < count; i++) {
400: Reference<?> r = refs.get(i);
401: try {
402: NbTestCase.assertGC(msg + " " + txts.get(i), r);
403: } catch (AssertionFailedError ex) {
404: if (t == null) {
405: t = ex;
406: } else {
407: Throwable last = t;
408: while (last.getCause() != null) {
409: last = last.getCause();
410: }
411: last.initCause(ex);
412: }
413: }
414: }
415: if (t != null) {
416: throw t;
417: }
418: }
419:
420: } // end of InstancesHandler
421: }
|