001: /*
002: * All content copyright (c) 2003-2006 Terracotta, Inc., except as may otherwise be noted in a separate copyright
003: * notice. All rights reserved.
004: */
005: package com.tc.logging;
006:
007: import org.apache.commons.io.FileUtils;
008: import org.apache.log4j.Appender;
009: import org.apache.log4j.ConsoleAppender;
010: import org.apache.log4j.Level;
011: import org.apache.log4j.Logger;
012: import org.apache.log4j.PatternLayout;
013: import org.apache.log4j.PropertyConfigurator;
014: import org.apache.log4j.RollingFileAppender;
015: import org.apache.log4j.varia.NullAppender;
016:
017: import com.tc.properties.TCProperties;
018: import com.tc.properties.TCPropertiesImpl;
019: import com.tc.util.Assert;
020: import com.tc.util.ProductInfo;
021:
022: import java.io.File;
023: import java.io.FileInputStream;
024: import java.io.IOException;
025: import java.io.PrintWriter;
026: import java.io.RandomAccessFile;
027: import java.io.StringWriter;
028: import java.nio.channels.FileChannel;
029: import java.nio.channels.FileLock;
030: import java.nio.channels.OverlappingFileLockException;
031: import java.util.ArrayList;
032: import java.util.Arrays;
033: import java.util.Iterator;
034: import java.util.Properties;
035: import java.util.Map.Entry;
036:
037: /**
038: * Factory class for obtaining TCLogger instances.
039: *
040: * @author teck
041: */
042: public class TCLogging {
043:
044: private static final int MAX_BUFFERED_LOG_MESSAGES = 10 * 1000;
045:
046: private static final String TERRACOTTA_L1_LOG_FILE_NAME = "terracotta-client.log";
047: private static final String TERRACOTTA_L2_LOG_FILE_NAME = "terracotta-server.log";
048: private static final String TERRACOTTA_GENERIC_LOG_FILE_NAME = "terracotta-generic.log";
049:
050: private static final String LOCK_FILE_NAME = ".terracotta-logging.lock";
051:
052: private static final String INTERNAL_LOGGER_NAMESPACE = "com.tc";
053: private static final String INTERNAL_LOGGER_NAMESPACE_WITH_DOT = INTERNAL_LOGGER_NAMESPACE
054: + ".";
055:
056: private static final String CUSTOMER_LOGGER_NAMESPACE = "com.terracottatech";
057: private static final String CUSTOMER_LOGGER_NAMESPACE_WITH_DOT = CUSTOMER_LOGGER_NAMESPACE
058: + ".";
059:
060: private static final String CONSOLE_LOGGER_NAME = CUSTOMER_LOGGER_NAMESPACE
061: + ".console";
062:
063: private static final String BENCH_LOGGER_NAME = "terracotta.bench";
064: private static final String LOGGING_PROPERTIES_SECTION = "logging";
065: private static final String MAX_LOG_FILE_SIZE_PROPERTY = "maxLogFileSize";
066: private static final int DEFAULT_MAX_LOG_FILE_SIZE = 512;
067: private static final String MAX_BACKUPS_PROPERTY = "maxBackups";
068: private static final int DEFAULT_MAX_BACKUPS = 20;
069: private static final String LOG4J_PROPERTIES_FILENAME = ".tc.dev.log4j.properties";
070:
071: private static final String CONSOLE_PATTERN = "%d %p - %m%n";
072: private static final String CONSOLE_PATTERN_DEVELOPMENT = "%d [%t] %p %c - %m%n";
073: // This next pattern is used when we're *only* logging to the console.
074: private static final String CONSOLE_LOGGING_ONLY_PATTERN = "[TC] %d %p - %m%n";
075: private static final String FILE_AND_JMX_PATTERN = "%d [%t] %p %c - %m%n";
076:
077: private static TCLogger console;
078: private static JMXAppender jmxAppender;
079: private static Appender consoleAppender;
080: private static DelegatingAppender delegateFileAppender;
081: private static DelegatingAppender delegateBufferingAppender;
082: private static boolean buffering;
083:
084: private static Logger[] allLoggers;
085:
086: private static File currentLoggingDirectory;
087: private static FileLock currentLoggingDirectoryFileLock = null;
088: private static boolean lockingDisabled = false;
089:
090: public static JMXAppender getJMXAppender() {
091: return jmxAppender;
092: }
093:
094: public static TCLogger getLogger(Class clazz) {
095: if (clazz == null) {
096: throw new IllegalArgumentException("Class cannot be null");
097: }
098: return getLogger(clazz.getName());
099: }
100:
101: public static TCLogger getLogger(String name) {
102: if ((name == null)
103: || !name.startsWith(INTERNAL_LOGGER_NAMESPACE_WITH_DOT)) {
104: // this comment here to make formatter sane
105: throw new IllegalArgumentException(
106: "Logger not in valid namepsace (ie. '"
107: + INTERNAL_LOGGER_NAMESPACE_WITH_DOT
108: + "' ): " + name);
109: }
110:
111: return new TCLoggerImpl(name);
112: }
113:
114: /**
115: * This method lets you get a logger w/o any name restrictoins. FOR TESTS ONLY (ie. not for shipping code)
116: */
117: public static TCLogger getTestingLogger(String name) {
118: if (name == null) {
119: throw new IllegalArgumentException("Name cannot be null");
120: }
121: return new TCLoggerImpl(name);
122: }
123:
124: /**
125: * This method lets you get a logger w/o any name restrictoins. FOR TESTS ONLY (ie. not for shipping code)
126: */
127: public static TCLogger getTestingLogger(Class clazz) {
128: if (clazz == null) {
129: throw new IllegalArgumentException("Class cannot be null");
130: }
131: return getTestingLogger(clazz.getName());
132: }
133:
134: public static TCLogger getBenchLogger() {
135: return new TCLoggerImpl(BENCH_LOGGER_NAME);
136: }
137:
138: // You want to look at CustomerLogging to get customer facing logger instances
139: static TCLogger getCustomerLogger(String name) {
140: if (name == null) {
141: throw new IllegalArgumentException("name cannot be null");
142: }
143:
144: name = CUSTOMER_LOGGER_NAMESPACE_WITH_DOT + name;
145:
146: if (CONSOLE_LOGGER_NAME.equals(name)) {
147: throw new IllegalArgumentException("Illegal name: " + name);
148: }
149:
150: return new TCLoggerImpl(name);
151: }
152:
153: // this method not public on purpose, use CustomerLogging.getConsoleLogger() instead
154: static TCLogger getConsoleLogger() {
155: return console;
156: }
157:
158: private static void reportLoggingError(Exception e) {
159: reportLoggingError(null, e);
160: }
161:
162: private static void reportLoggingError(String message, Exception e) {
163: String newLine = System.getProperty("line.separator");
164: StringBuffer errorMsg = new StringBuffer(newLine);
165:
166: if (message != null) {
167: errorMsg.append("WARN: ").append(message).append(newLine);
168: }
169:
170: if (e != null) {
171: StringWriter sw = new StringWriter();
172: e.printStackTrace(new PrintWriter(sw));
173: errorMsg.append(sw.toString());
174: }
175:
176: System.err.println(errorMsg.toString());
177: }
178:
179: private static boolean developmentConfiguration() {
180: try {
181: Properties devLoggingProperties = new Properties();
182:
183: // Specify the order of LEAST importantance; last one in wins
184: File[] devLoggingLocations = new File[] {
185: new File(System.getProperty("user.home"),
186: LOG4J_PROPERTIES_FILENAME),
187: new File(System.getProperty("user.dir"),
188: LOG4J_PROPERTIES_FILENAME) };
189:
190: boolean devLog4JPropsFilePresent = false;
191: for (int pos = 0; pos < devLoggingLocations.length; ++pos) {
192: File propFile = devLoggingLocations[pos];
193: if (propFile.isFile() && propFile.canRead()) {
194: devLog4JPropsFilePresent = true;
195: devLoggingProperties.load(new FileInputStream(
196: propFile));
197: }
198: }
199: if (devLog4JPropsFilePresent) {
200: Logger.getRootLogger().setLevel(Level.INFO);
201: PropertyConfigurator.configure(devLoggingProperties);
202: return true;
203: }
204: } catch (Exception e) {
205: reportLoggingError(e);
206: }
207:
208: return false;
209: }
210:
211: /**
212: * <strong>FOR TESTS ONLY</strong>. This allows tests to successfully blow away directories containing log files on
213: * Windows. This is a bit of a hack, but working around it is otherwise an enormous pain — tests only fail on
214: * Windows, and you must then very carefully go around, figure out exactly why, and then work around it. Use of this
215: * method makes everything a great deal simpler.
216: */
217: public static synchronized void disableLocking() {
218: lockingDisabled = true;
219:
220: if (currentLoggingDirectoryFileLock != null) {
221: try {
222: currentLoggingDirectoryFileLock.release();
223: currentLoggingDirectoryFileLock = null;
224: } catch (IOException ioe) {
225: throw Assert.failure("Unable to release file lock?",
226: ioe);
227: }
228: }
229: }
230:
231: public static final int PROCESS_TYPE_GENERIC = 0;
232: public static final int PROCESS_TYPE_L1 = 1;
233: public static final int PROCESS_TYPE_L2 = 2;
234:
235: public static void setLogDirectory(File theDirectory,
236: int processType) {
237: Assert.assertNotNull(theDirectory);
238:
239: if (theDirectory.getName().trim().equalsIgnoreCase("stdout:")
240: || theDirectory.getName().trim().equalsIgnoreCase(
241: "stderr:")) {
242: if (currentLoggingDirectory != null
243: && currentLoggingDirectory.getName().trim()
244: .equalsIgnoreCase(theDirectory.getName())) {
245: // Nothing to do; great!
246: return;
247: }
248:
249: delegateFileAppender.setDelegate(new NullAppender());
250: consoleAppender.setLayout(new PatternLayout(
251: CONSOLE_LOGGING_ONLY_PATTERN));
252:
253: // Logger.addAppender() doesn't double-add, so this is safe
254: Logger.getRootLogger().addAppender(consoleAppender);
255:
256: if (buffering) {
257: BufferingAppender realBufferingAppender = (BufferingAppender) delegateBufferingAppender
258: .setDelegate(new NullAppender());
259: realBufferingAppender
260: .stopAndSendContentsTo(consoleAppender);
261: realBufferingAppender.close();
262: buffering = false;
263: }
264:
265: boolean stdout = theDirectory.getName().trim()
266: .equalsIgnoreCase("stdout:");
267: getConsoleLogger().info(
268: "All logging information now output to standard "
269: + (stdout ? "output" : "error") + ".");
270:
271: return;
272: }
273:
274: synchronized (TCLogging.class) {
275: if (currentLoggingDirectory != null) {
276: try {
277: if (theDirectory.getCanonicalPath().equals(
278: currentLoggingDirectory.getCanonicalPath())) {
279: return;
280: }
281: } catch (IOException ioe) {
282: // oh, well -- what can we do? we'll continue on.
283: }
284: }
285: }
286:
287: try {
288: FileUtils.forceMkdir(theDirectory);
289: } catch (IOException ioe) {
290: reportLoggingError("We can't create the directory '"
291: + theDirectory.getAbsolutePath()
292: + "' that you specified for your logs.", ioe);
293: return;
294: }
295:
296: if (!theDirectory.canWrite()) {
297: // formatting
298: reportLoggingError("The log directory, '"
299: + theDirectory.getAbsolutePath()
300: + "', can't be written to.", null);
301: return;
302: }
303:
304: FileLock this DirectoryLock = null;
305:
306: if (!lockingDisabled) {
307: File lockFile = new File(theDirectory, LOCK_FILE_NAME);
308:
309: try {
310: if (!lockFile.exists())
311: lockFile.createNewFile();
312: Assert.eval(lockFile.exists());
313: FileChannel channel = new RandomAccessFile(lockFile,
314: "rw").getChannel();
315: this DirectoryLock = channel.tryLock();
316:
317: if (this DirectoryLock == null) {
318: reportLoggingError(
319: "The log directory, '"
320: + theDirectory.getAbsolutePath()
321: + "', is already in use by another "
322: + "Terracotta process. Logging will proceed to the console only.",
323: null);
324: return;
325: }
326:
327: } catch (OverlappingFileLockException ofle) {
328: // This VM already holds the lock; no problem
329: } catch (IOException ioe) {
330: reportLoggingError(
331: "We can't lock the file '"
332: + lockFile.getAbsolutePath()
333: + "', to make sure that only one "
334: + "Terracotta process is using this directory for logging. This may be a permission "
335: + "issue, or some unexpected error. Logging will proceed to the console only.",
336: ioe);
337: return;
338: }
339: }
340:
341: RollingFileAppender newFileAppender;
342:
343: String logFileName;
344:
345: switch (processType) {
346: case PROCESS_TYPE_L1:
347: logFileName = TERRACOTTA_L1_LOG_FILE_NAME;
348: break;
349:
350: case PROCESS_TYPE_L2:
351: logFileName = TERRACOTTA_L2_LOG_FILE_NAME;
352: break;
353:
354: case PROCESS_TYPE_GENERIC:
355: logFileName = TERRACOTTA_GENERIC_LOG_FILE_NAME;
356: break;
357:
358: default:
359: throw Assert
360: .failure("Unknown process type: " + processType);
361: }
362:
363: String logFilePath = new File(theDirectory, logFileName)
364: .getAbsolutePath();
365:
366: synchronized (TCLogging.class) {
367: try {
368: TCProperties props = TCPropertiesImpl.getProperties()
369: .getPropertiesFor(LOGGING_PROPERTIES_SECTION);
370: newFileAppender = new RollingFileAppender(
371: new PatternLayout(FILE_AND_JMX_PATTERN),
372: logFilePath, true);
373: newFileAppender.setName("file appender");
374: int maxLogFileSize = props.getInt(
375: MAX_LOG_FILE_SIZE_PROPERTY,
376: DEFAULT_MAX_LOG_FILE_SIZE);
377: newFileAppender.setMaxFileSize(maxLogFileSize + "MB");
378: newFileAppender.setMaxBackupIndex(props.getInt(
379: MAX_BACKUPS_PROPERTY, DEFAULT_MAX_BACKUPS));
380:
381: // This makes us start with a new file each time.
382: newFileAppender.rollOver();
383:
384: // Note: order of operations is very important here. We start the new appender before we close and remove the
385: // old one so that you don't drop any log records.
386: Appender oldFileAppender = delegateFileAppender
387: .setDelegate(newFileAppender);
388:
389: if (oldFileAppender != null) {
390: oldFileAppender.close();
391: }
392:
393: if (buffering) {
394: BufferingAppender realBufferingAppender = (BufferingAppender) delegateBufferingAppender
395: .setDelegate(new NullAppender());
396: realBufferingAppender
397: .stopAndSendContentsTo(delegateFileAppender);
398: realBufferingAppender.close();
399: buffering = false;
400: }
401:
402: currentLoggingDirectory = theDirectory;
403:
404: if (currentLoggingDirectoryFileLock != null)
405: currentLoggingDirectoryFileLock.release();
406: currentLoggingDirectoryFileLock = this DirectoryLock;
407: } catch (IOException ioe) {
408: reportLoggingError(
409: "We were unable to switch the logging system to log to '"
410: + logFilePath + "'.", ioe);
411: }
412: }
413:
414: getConsoleLogger().info("Log file: '" + logFilePath + "'.");
415: writeSystemProperties();
416: }
417:
418: static {
419: ClassLoader prevLoader = Thread.currentThread()
420: .getContextClassLoader();
421: Thread.currentThread().setContextClassLoader(
422: TCLogging.class.getClassLoader());
423:
424: try {
425: currentLoggingDirectory = null;
426:
427: Logger jettyLogger = Logger.getLogger("org.mortbay");
428: jettyLogger.setLevel(Level.OFF);
429:
430: Logger internalLogger = Logger
431: .getLogger(INTERNAL_LOGGER_NAMESPACE);
432: Logger customerLogger = Logger
433: .getLogger(CUSTOMER_LOGGER_NAMESPACE);
434: Logger consoleLogger = Logger
435: .getLogger(CONSOLE_LOGGER_NAME);
436: Logger benchLogger = Logger.getLogger(BENCH_LOGGER_NAME);
437:
438: /**
439: * Don't add consoleLogger to allLoggers because it's a child of customerLogger, so it shouldn't get any
440: * appenders. If you DO add consoleLogger here, you'll see duplicate messages in the log file.
441: */
442: allLoggers = new Logger[] { internalLogger, customerLogger,
443: benchLogger };
444:
445: console = new TCLoggerImpl(CONSOLE_LOGGER_NAME);
446:
447: internalLogger.setLevel(Level.INFO);
448: customerLogger.setLevel(Level.INFO);
449: consoleLogger.setLevel(Level.INFO);
450: benchLogger.setLevel(Level.INFO);
451:
452: boolean isDev = developmentConfiguration();
453:
454: consoleAppender = new ConsoleAppender(new PatternLayout(
455: CONSOLE_PATTERN), ConsoleAppender.SYSTEM_ERR);
456:
457: if (!isDev) {
458: // Only the console logger goes to the console (by default)
459: consoleLogger.addAppender(consoleAppender);
460: } else {
461: consoleAppender.setLayout(new PatternLayout(
462: CONSOLE_PATTERN_DEVELOPMENT));
463: // For non-customer environments, send all logging to the console...
464: Logger.getRootLogger().addAppender(consoleAppender);
465: }
466:
467: delegateFileAppender = new DelegatingAppender(
468: new NullAppender());
469: addToAllLoggers(delegateFileAppender);
470:
471: BufferingAppender realBufferingAppender;
472: realBufferingAppender = new BufferingAppender(
473: MAX_BUFFERED_LOG_MESSAGES);
474: realBufferingAppender.setName("buffering appender");
475: delegateBufferingAppender = new DelegatingAppender(
476: realBufferingAppender);
477: addToAllLoggers(delegateBufferingAppender);
478: buffering = true;
479:
480: // all logging goes to JMX based appender
481: jmxAppender = new JMXAppender();
482: jmxAppender.setLayout(new PatternLayout(
483: FILE_AND_JMX_PATTERN));
484: jmxAppender.setName("JMX appender");
485: addToAllLoggers(jmxAppender);
486:
487: if (!isDev) {
488: CustomerLogging.getGenericCustomerLogger().info(
489: "New logging session started.");
490: }
491:
492: writeVersion();
493: } catch (Exception e) {
494: reportLoggingError(e);
495: } finally {
496: Thread.currentThread().setContextClassLoader(prevLoader);
497: }
498: }
499:
500: // for test use only!
501: public static void addAppender(String loggerName,
502: TCAppender appender) {
503: new TCLoggerImpl(loggerName).getLogger().addAppender(
504: new Log4JAappenderToTCAppender(appender));
505: }
506:
507: private static void addToAllLoggers(Appender appender) {
508: for (int i = 0; i < allLoggers.length; ++i)
509: allLoggers[i].addAppender(appender);
510: }
511:
512: private static void writeVersion() {
513: ProductInfo info = ProductInfo.getInstance();
514: CustomerLogging.getConsoleLogger().info(info.toLongString());
515: getLogger(TCLogging.class).info(info.toLongString());
516: }
517:
518: private static void writeSystemProperties() {
519: try {
520: Properties properties = System.getProperties();
521: int maxKeyLength = 1;
522:
523: ArrayList keys = new ArrayList();
524: Iterator iter = properties.entrySet().iterator();
525: while (iter.hasNext()) {
526: Entry entry = (Entry) iter.next();
527: Object objKey = entry.getKey();
528: Object objValue = entry.getValue();
529:
530: // It's possible someone is being bad and shoving non-String keys or values into system props
531: if (objKey instanceof String
532: && objValue instanceof String) {
533: String key = (String) objKey;
534: if (key != null) {
535: keys.add(key);
536: }
537: maxKeyLength = Math.max(maxKeyLength,
538: key == null ? 0 : key.length());
539: }
540: }
541:
542: StringBuffer data = new StringBuffer();
543: data
544: .append("========================================================================\n");
545: data
546: .append("All Java System Properties for this Terracotta instance:\n");
547:
548: String[] sortedKeys = (String[]) keys
549: .toArray(new String[keys.size()]);
550: Arrays.sort(sortedKeys);
551: for (int i = 0; i < sortedKeys.length; ++i) {
552: String key = sortedKeys[i];
553: String value = (String) properties.get(key);
554:
555: while (key.length() < maxKeyLength)
556: key += " ";
557:
558: data.append(key + ": " + value + "\n");
559: }
560:
561: data
562: .append("========================================================================\n");
563:
564: getLogger(TCLogging.class).info(data.toString());
565: } catch (Throwable t) {
566: // don't let exceptions here be fatal
567: t.printStackTrace();
568: }
569: }
570:
571: // This method for use in tests only
572: public static void closeFileAppender() {
573: if (delegateFileAppender != null)
574: delegateFileAppender.close();
575: }
576:
577: }
|