View Javadoc

1   //
2   //  ========================================================================
3   //  Copyright (c) 1995-2013 Mort Bay Consulting Pty. Ltd.
4   //  ------------------------------------------------------------------------
5   //  All rights reserved. This program and the accompanying materials
6   //  are made available under the terms of the Eclipse Public License v1.0
7   //  and Apache License v2.0 which accompanies this distribution.
8   //
9   //      The Eclipse Public License is available at
10  //      http://www.eclipse.org/legal/epl-v10.html
11  //
12  //      The Apache License v2.0 is available at
13  //      http://www.opensource.org/licenses/apache2.0.php
14  //
15  //  You may elect to redistribute this code under either of these licenses.
16  //  ========================================================================
17  //
18  
19  package org.eclipse.jetty.util.log;
20  
21  import java.io.PrintStream;
22  import java.security.AccessControlException;
23  import java.util.Properties;
24  
25  import org.eclipse.jetty.util.DateCache;
26  import org.eclipse.jetty.util.annotation.ManagedAttribute;
27  import org.eclipse.jetty.util.annotation.ManagedObject;
28  
29  /**
30   * StdErr Logging implementation. 
31   * <p>
32   * A Jetty {@link Logger} that sends all logs to STDERR ({@link System#err}) with basic formatting.
33   * <p>
34   * Supports named loggers, and properties based configuration. 
35   * <p>
36   * Configuration Properties:
37   * <dl>
38   *   <dt>${name|hierarchy}.LEVEL=(ALL|DEBUG|INFO|WARN|OFF)</dt>
39   *   <dd>
40   *   Sets the level that the Logger should log at.<br/>
41   *   Names can be a package name, or a fully qualified class name.<br/>
42   *   Default: INFO<br/>
43   *   <br/>
44   *   Examples:
45   *   <dl>
46   *   <dt>org.eclipse.jetty.LEVEL=WARN</dt>
47   *   <dd>indicates that all of the jetty specific classes, in any package that 
48   *   starts with <code>org.eclipse.jetty</code> should log at level WARN.</dd>
49   *   <dt>org.eclipse.jetty.io.ChannelEndPoint.LEVEL=ALL</dt>
50   *   <dd>indicates that the specific class, ChannelEndPoint, should log all
51   *   logging events that it can generate, including DEBUG, INFO, WARN (and even special
52   *   internally ignored exception cases).</dd>
53   *   </dl>  
54   *   </dd>
55   *   
56   *   <dt>${name}.SOURCE=(true|false)</dt>
57   *   <dd>
58   *   Logger specific, attempt to print the java source file name and line number
59   *   where the logging event originated from.<br/>
60   *   Name must be a fully qualified class name (package name hierarchy is not supported
61   *   by this configurable)<br/>
62   *   Warning: this is a slow operation and will have an impact on performance!<br/>
63   *   Default: false
64   *   </dd>
65   *   
66   *   <dt>${name}.STACKS=(true|false)</dt>
67   *   <dd>
68   *   Logger specific, control the display of stacktraces.<br/>
69   *   Name must be a fully qualified class name (package name hierarchy is not supported
70   *   by this configurable)<br/>
71   *   Default: true
72   *   </dd>
73   *   
74   *   <dt>org.eclipse.jetty.util.log.stderr.SOURCE=(true|false)</dt>
75   *   <dd>Special Global Configuration, attempt to print the java source file name and line number
76   *   where the logging event originated from.<br/>
77   *   Default: false
78   *   </dd>
79   *   
80   *   <dt>org.eclipse.jetty.util.log.stderr.LONG=(true|false)</dt>
81   *   <dd>Special Global Configuration, when true, output logging events to STDERR using
82   *   long form, fully qualified class names.  when false, use abbreviated package names<br/>
83   *   Default: false
84   *   </dd>
85   *   <dt>org.eclipse.jetty.util.log.stderr.ESCAPE=(true|false)</dt>
86   *   <dd>Global Configuration, when true output logging events to STDERR are always
87   *   escaped so that control characters are replaced with '?";  '\r' with '<' and '\n' replaced '|'<br/>
88   *   Default: true
89   *   </dd>
90   * </dl>
91   */
92  @ManagedObject("Jetty StdErr Logging Implementation")
93  public class StdErrLog extends AbstractLogger
94  {
95      private static final String EOL = System.getProperty("line.separator");
96      private static DateCache _dateCache;
97      private static final Properties __props = new Properties();
98  
99      private final static boolean __source = Boolean.parseBoolean(Log.__props.getProperty("org.eclipse.jetty.util.log.SOURCE",
100             Log.__props.getProperty("org.eclipse.jetty.util.log.stderr.SOURCE","false")));
101     private final static boolean __long = Boolean.parseBoolean(Log.__props.getProperty("org.eclipse.jetty.util.log.stderr.LONG","false"));
102     private final static boolean __escape = Boolean.parseBoolean(Log.__props.getProperty("org.eclipse.jetty.util.log.stderr.ESCAPE","true"));
103 
104     static
105     {
106         __props.putAll(Log.__props);
107 
108         String deprecatedProperties[] =
109         { "DEBUG", "org.eclipse.jetty.util.log.DEBUG", "org.eclipse.jetty.util.log.stderr.DEBUG" };
110 
111         // Toss a message to users about deprecated system properties
112         for (String deprecatedProp : deprecatedProperties)
113         {
114             if (System.getProperty(deprecatedProp) != null)
115             {
116                 System.err.printf("System Property [%s] has been deprecated! (Use org.eclipse.jetty.LEVEL=DEBUG instead)%n",deprecatedProp);
117             }
118         }
119 
120         try
121         {
122             _dateCache = new DateCache("yyyy-MM-dd HH:mm:ss");
123         }
124         catch (Exception x)
125         {
126             x.printStackTrace(System.err);
127         }
128     }
129 
130     public static final int LEVEL_ALL = 0;
131     public static final int LEVEL_DEBUG = 1;
132     public static final int LEVEL_INFO = 2;
133     public static final int LEVEL_WARN = 3;
134     public static final int LEVEL_OFF = 10;
135 
136     private int _level = LEVEL_INFO;
137     // Level that this Logger was configured as (remembered in special case of .setDebugEnabled())
138     private int _configuredLevel;
139     private PrintStream _stderr = null;
140     private boolean _source = __source;
141     // Print the long form names, otherwise use abbreviated
142     private boolean _printLongNames = __long;
143     // The full log name, as provided by the system.
144     private final String _name;
145     // The abbreviated log name (used by default, unless _long is specified)
146     private final String _abbrevname;
147     private boolean _hideStacks = false;
148 
149     /**
150      * Obtain a StdErrLog reference for the specified class, a convenience method used most often during testing to allow for control over a specific logger.
151      * <p>
152      * Must be actively using StdErrLog as the Logger implementation.
153      * 
154      * @param clazz
155      *            the Class reference for the logger to use.
156      * @return the StdErrLog logger
157      * @throws RuntimeException
158      *             if StdErrLog is not the active Logger implementation.
159      */
160     public static StdErrLog getLogger(Class<?> clazz)
161     {
162         Logger log = Log.getLogger(clazz);
163         if (log instanceof StdErrLog)
164         {
165             return (StdErrLog)log;
166         }
167         throw new RuntimeException("Logger for " + clazz + " is not of type StdErrLog");
168     }
169 
170     /**
171      * Construct an anonymous StdErrLog (no name).
172      * <p>
173      * NOTE: Discouraged usage!
174      */
175     public StdErrLog()
176     {
177         this(null);
178     }
179 
180     /**
181      * Construct a named StdErrLog using the {@link Log} defined properties
182      * 
183      * @param name
184      *            the name of the logger
185      */
186     public StdErrLog(String name)
187     {
188         this(name,__props);
189     }
190 
191     /**
192      * Construct a named Logger using the provided properties to configure logger.
193      * 
194      * @param name
195      *            the name of the logger
196      * @param props
197      *            the configuration properties
198      */
199     public StdErrLog(String name, Properties props)
200     {
201         if (props!=null && props!=__props)
202             __props.putAll(props);
203         this._name = name == null?"":name;
204         this._abbrevname = condensePackageString(this._name);
205         this._level = getLoggingLevel(props,this._name);
206         this._configuredLevel = this._level;
207 
208         try
209         {
210             String source = getLoggingProperty(props,_name,"SOURCE");
211             _source = source==null?__source:Boolean.parseBoolean(source);
212         }
213         catch (AccessControlException ace)
214         {
215             _source = __source;
216         }
217 
218         try
219         {
220             // allow stacktrace display to be controlled by properties as well
221             String stacks = getLoggingProperty(props,_name,"STACKS");
222             _hideStacks = stacks==null?false:!Boolean.parseBoolean(stacks);
223         }
224         catch (AccessControlException ignore)
225         {
226             /* ignore */
227         }        
228     }
229 
230     /**
231      * Get the Logging Level for the provided log name. Using the FQCN first, then each package segment from longest to
232      * shortest.
233      *
234      * @param props
235      *            the properties to check
236      * @param name
237      *            the name to get log for
238      * @return the logging level
239      */
240     public static int getLoggingLevel(Properties props, final String name)
241     {
242         // Calculate the level this named logger should operate under.
243         // Checking with FQCN first, then each package segment from longest to shortest.
244         String nameSegment = name;
245 
246         while ((nameSegment != null) && (nameSegment.length() > 0))
247         {
248             String levelStr = props.getProperty(nameSegment + ".LEVEL");
249             // System.err.printf("[StdErrLog.CONFIG] Checking for property [%s.LEVEL] = %s%n",nameSegment,levelStr);
250             int level = getLevelId(nameSegment + ".LEVEL",levelStr);
251             if (level != (-1))
252             {
253                 return level;
254             }
255 
256             // Trim and try again.
257             int idx = nameSegment.lastIndexOf('.');
258             if (idx >= 0)
259             {
260                 nameSegment = nameSegment.substring(0,idx);
261             }
262             else
263             {
264                 nameSegment = null;
265             }
266         }
267 
268         // Default Logging Level
269         return getLevelId("log.LEVEL",props.getProperty("log.LEVEL","INFO"));
270     }
271     
272     public static String getLoggingProperty(Properties props, String name, String property)
273     {
274         // Calculate the level this named logger should operate under.
275         // Checking with FQCN first, then each package segment from longest to shortest.
276         String nameSegment = name;
277 
278         while ((nameSegment != null) && (nameSegment.length() > 0))
279         {
280             String s = props.getProperty(nameSegment+"."+property);
281             if (s!=null)
282                 return s;
283 
284             // Trim and try again.
285             int idx = nameSegment.lastIndexOf('.');
286             nameSegment = (idx >= 0)?nameSegment.substring(0,idx):null;
287         }
288 
289         return null;
290     }
291 
292     protected static int getLevelId(String levelSegment, String levelName)
293     {
294         if (levelName == null)
295         {
296             return -1;
297         }
298         String levelStr = levelName.trim();
299         if ("ALL".equalsIgnoreCase(levelStr))
300         {
301             return LEVEL_ALL;
302         }
303         else if ("DEBUG".equalsIgnoreCase(levelStr))
304         {
305             return LEVEL_DEBUG;
306         }
307         else if ("INFO".equalsIgnoreCase(levelStr))
308         {
309             return LEVEL_INFO;
310         }
311         else if ("WARN".equalsIgnoreCase(levelStr))
312         {
313             return LEVEL_WARN;
314         }
315         else if ("OFF".equalsIgnoreCase(levelStr))
316         {
317             return LEVEL_OFF;
318         }
319 
320         System.err.println("Unknown StdErrLog level [" + levelSegment + "]=[" + levelStr + "], expecting only [ALL, DEBUG, INFO, WARN, OFF] as values.");
321         return -1;
322     }
323 
324     /**
325      * Condenses a classname by stripping down the package name to just the first character of each package name
326      * segment.Configured
327      * <p>
328      *
329      * <pre>
330      * Examples:
331      * "org.eclipse.jetty.test.FooTest"           = "oejt.FooTest"
332      * "org.eclipse.jetty.server.logging.LogTest" = "orjsl.LogTest"
333      * </pre>
334      *
335      * @param classname
336      *            the fully qualified class name
337      * @return the condensed name
338      */
339     protected static String condensePackageString(String classname)
340     {
341         String parts[] = classname.split("\\.");
342         StringBuilder dense = new StringBuilder();
343         for (int i = 0; i < (parts.length - 1); i++)
344         {
345             dense.append(parts[i].charAt(0));
346         }
347         if (dense.length() > 0)
348         {
349             dense.append('.');
350         }
351         dense.append(parts[parts.length - 1]);
352         return dense.toString();
353     }
354 
355     public String getName()
356     {
357         return _name;
358     }
359 
360     public void setPrintLongNames(boolean printLongNames)
361     {
362         this._printLongNames = printLongNames;
363     }
364 
365     public boolean isPrintLongNames()
366     {
367         return this._printLongNames;
368     }
369 
370     public boolean isHideStacks()
371     {
372         return _hideStacks;
373     }
374 
375     public void setHideStacks(boolean hideStacks)
376     {
377         _hideStacks = hideStacks;
378     }
379 
380     /* ------------------------------------------------------------ */
381     /**
382      * Is the source of a log, logged
383      *
384      * @return true if the class, method, file and line number of a log is logged.
385      */
386     public boolean isSource()
387     {
388         return _source;
389     }
390 
391     /* ------------------------------------------------------------ */
392     /**
393      * Set if a log source is logged.
394      *
395      * @param source
396      *            true if the class, method, file and line number of a log is logged.
397      */
398     public void setSource(boolean source)
399     {
400         _source = source;
401     }
402 
403     public void warn(String msg, Object... args)
404     {
405         if (_level <= LEVEL_WARN)
406         {
407             StringBuilder buffer = new StringBuilder(64);
408             format(buffer,":WARN:",msg,args);
409             (_stderr==null?System.err:_stderr).println(buffer);
410         }
411     }
412 
413     public void warn(Throwable thrown)
414     {
415         warn("",thrown);
416     }
417 
418     public void warn(String msg, Throwable thrown)
419     {
420         if (_level <= LEVEL_WARN)
421         {
422             StringBuilder buffer = new StringBuilder(64);
423             format(buffer,":WARN:",msg,thrown);
424             (_stderr==null?System.err:_stderr).println(buffer);
425         }
426     }
427 
428     public void info(String msg, Object... args)
429     {
430         if (_level <= LEVEL_INFO)
431         {
432             StringBuilder buffer = new StringBuilder(64);
433             format(buffer,":INFO:",msg,args);
434             (_stderr==null?System.err:_stderr).println(buffer);
435         }
436     }
437 
438     public void info(Throwable thrown)
439     {
440         info("",thrown);
441     }
442 
443     public void info(String msg, Throwable thrown)
444     {
445         if (_level <= LEVEL_INFO)
446         {
447             StringBuilder buffer = new StringBuilder(64);
448             format(buffer,":INFO:",msg,thrown);
449             (_stderr==null?System.err:_stderr).println(buffer);
450         }
451     }
452 
453     @ManagedAttribute("is debug enabled for root logger Log.LOG")
454     public boolean isDebugEnabled()
455     {
456         return (_level <= LEVEL_DEBUG);
457     }
458 
459     /**
460      * Legacy interface where a programmatic configuration of the logger level
461      * is done as a wholesale approach.
462      */
463     @Override
464     public void setDebugEnabled(boolean enabled)
465     {
466         if (enabled)
467         {
468             this._level = LEVEL_DEBUG;
469 
470             for (Logger log : Log.getLoggers().values())
471             {                
472                 if (log.getName().startsWith(getName()) && log instanceof StdErrLog)
473                     ((StdErrLog)log).setLevel(LEVEL_DEBUG);
474             }
475         }
476         else
477         {
478             this._level = this._configuredLevel;
479 
480             for (Logger log : Log.getLoggers().values())
481             {
482                 if (log.getName().startsWith(getName()) && log instanceof StdErrLog)
483                     ((StdErrLog)log).setLevel(((StdErrLog)log)._configuredLevel);
484             }
485         }
486     }
487 
488     public int getLevel()
489     {
490         return _level;
491     }
492 
493     /**
494      * Set the level for this logger.
495      * <p>
496      * Available values ({@link StdErrLog#LEVEL_ALL}, {@link StdErrLog#LEVEL_DEBUG}, {@link StdErrLog#LEVEL_INFO},
497      * {@link StdErrLog#LEVEL_WARN})
498      *
499      * @param level
500      *            the level to set the logger to
501      */
502     public void setLevel(int level)
503     {
504         this._level = level;
505     }
506 
507     public void setStdErrStream(PrintStream stream)
508     {
509         this._stderr = stream==System.err?null:stream;
510     }
511 
512     public void debug(String msg, Object... args)
513     {
514         if (_level <= LEVEL_DEBUG)
515         {
516             StringBuilder buffer = new StringBuilder(64);
517             format(buffer,":DBUG:",msg,args);
518             (_stderr==null?System.err:_stderr).println(buffer);
519         }
520     }
521 
522     public void debug(Throwable thrown)
523     {
524         debug("",thrown);
525     }
526 
527     public void debug(String msg, Throwable thrown)
528     {
529         if (_level <= LEVEL_DEBUG)
530         {
531             StringBuilder buffer = new StringBuilder(64);
532             format(buffer,":DBUG:",msg,thrown);
533             (_stderr==null?System.err:_stderr).println(buffer);
534         }
535     }
536 
537     private void format(StringBuilder buffer, String level, String msg, Object... args)
538     {
539         long now = System.currentTimeMillis();
540         int ms=(int)(now%1000);
541         String d = _dateCache.now();
542         tag(buffer,d,ms,level);
543         format(buffer,msg,args);
544     }
545 
546     private void format(StringBuilder buffer, String level, String msg, Throwable thrown)
547     {
548         format(buffer,level,msg);
549         if (isHideStacks())
550         {
551             format(buffer,": "+String.valueOf(thrown));
552         }
553         else
554         {
555             format(buffer,thrown);
556         }
557     }
558 
559     private void tag(StringBuilder buffer, String d, int ms, String tag)
560     {
561         buffer.setLength(0);
562         buffer.append(d);
563         if (ms > 99)
564         {
565             buffer.append('.');
566         }
567         else if (ms > 9)
568         {
569             buffer.append(".0");
570         }
571         else
572         {
573             buffer.append(".00");
574         }
575         buffer.append(ms).append(tag);
576         if (_printLongNames)
577         {
578             buffer.append(_name);
579         }
580         else
581         {
582             buffer.append(_abbrevname);
583         }
584         buffer.append(':');
585         buffer.append(Thread.currentThread().getName()).append(": ");
586         if (_source)
587         {
588             Throwable source = new Throwable();
589             StackTraceElement[] frames = source.getStackTrace();
590             for (int i = 0; i < frames.length; i++)
591             {
592                 final StackTraceElement frame = frames[i];
593                 String clazz = frame.getClassName();
594                 if (clazz.equals(StdErrLog.class.getName()) || clazz.equals(Log.class.getName()))
595                 {
596                     continue;
597                 }
598                 if (!_printLongNames && clazz.startsWith("org.eclipse.jetty."))
599                 {
600                     buffer.append(condensePackageString(clazz));
601                 }
602                 else
603                 {
604                     buffer.append(clazz);
605                 }
606                 buffer.append('#').append(frame.getMethodName());
607                 if (frame.getFileName() != null)
608                 {
609                     buffer.append('(').append(frame.getFileName()).append(':').append(frame.getLineNumber()).append(')');
610                 }
611                 buffer.append(':');
612                 break;
613             }
614         }
615     }
616 
617     private void format(StringBuilder builder, String msg, Object... args)
618     {
619         if (msg == null)
620         {
621             msg = "";
622             for (int i = 0; i < args.length; i++)
623             {
624                 msg += "{} ";
625             }
626         }
627         String braces = "{}";
628         int start = 0;
629         for (Object arg : args)
630         {
631             int bracesIndex = msg.indexOf(braces,start);
632             if (bracesIndex < 0)
633             {
634                 escape(builder,msg.substring(start));
635                 builder.append(" ");
636                 builder.append(arg);
637                 start = msg.length();
638             }
639             else
640             {
641                 escape(builder,msg.substring(start,bracesIndex));
642                 builder.append(String.valueOf(arg));
643                 start = bracesIndex + braces.length();
644             }
645         }
646         escape(builder,msg.substring(start));
647     }
648 
649     private void escape(StringBuilder builder, String string)
650     {
651         if (__escape)
652         {
653             for (int i = 0; i < string.length(); ++i)
654             {
655                 char c = string.charAt(i);
656                 if (Character.isISOControl(c))
657                 {
658                     if (c == '\n')
659                     {
660                         builder.append('|');
661                     }
662                     else if (c == '\r')
663                     {
664                         builder.append('<');
665                     }
666                     else
667                     {
668                         builder.append('?');
669                     }
670                 }
671                 else
672                 {
673                     builder.append(c);
674                 }
675             }
676         }
677         else
678             builder.append(string);
679     }
680 
681     private void format(StringBuilder buffer, Throwable thrown)
682     {
683         if (thrown == null)
684         {
685             buffer.append("null");
686         }
687         else
688         {
689             buffer.append(EOL);
690             format(buffer,thrown.toString());
691             StackTraceElement[] elements = thrown.getStackTrace();
692             for (int i = 0; elements != null && i < elements.length; i++)
693             {
694                 buffer.append(EOL).append("\tat ");
695                 format(buffer,elements[i].toString());
696             }
697 
698             Throwable cause = thrown.getCause();
699             if (cause != null && cause != thrown)
700             {
701                 buffer.append(EOL).append("Caused by: ");
702                 format(buffer,cause);
703             }
704         }
705     }
706 
707 
708     /**
709      * Create a Child Logger of this Logger.
710      */
711     @Override
712     protected Logger newLogger(String fullname)
713     {
714         StdErrLog logger = new StdErrLog(fullname);
715         // Preserve configuration for new loggers configuration
716         logger.setPrintLongNames(_printLongNames);
717         logger._stderr = this._stderr;
718 
719         // Force the child to have any programmatic configuration
720         if (_level!=_configuredLevel)
721             logger._level=_level;
722 
723         return logger;
724     }
725 
726     @Override
727     public String toString()
728     {
729         StringBuilder s = new StringBuilder();
730         s.append("StdErrLog:");
731         s.append(_name);
732         s.append(":LEVEL=");
733         switch (_level)
734         {
735             case LEVEL_ALL:
736                 s.append("ALL");
737                 break;
738             case LEVEL_DEBUG:
739                 s.append("DEBUG");
740                 break;
741             case LEVEL_INFO:
742                 s.append("INFO");
743                 break;
744             case LEVEL_WARN:
745                 s.append("WARN");
746                 break;
747             default:
748                 s.append("?");
749                 break;
750         }
751         return s.toString();
752     }
753 
754     public static void setProperties(Properties props)
755     {
756         __props.clear();
757         __props.putAll(props);
758     }
759 
760     public void ignore(Throwable ignored)
761     {
762         if (_level <= LEVEL_ALL)
763         {
764             StringBuilder buffer = new StringBuilder(64);
765             format(buffer,":IGNORED:","",ignored);
766             (_stderr==null?System.err:_stderr).println(buffer);
767         }
768     }
769 }