View Javadoc

1   //
2   //  ========================================================================
3   //  Copyright (c) 1995-2016 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  import java.util.logging.Level;
25  
26  import org.eclipse.jetty.util.DateCache;
27  import org.eclipse.jetty.util.annotation.ManagedAttribute;
28  import org.eclipse.jetty.util.annotation.ManagedObject;
29  
30  /**
31   * StdErr Logging implementation. 
32   * <p>
33   * A Jetty {@link Logger} that sends all logs to STDERR ({@link System#err}) with basic formatting.
34   * <p>
35   * Supports named loggers, and properties based configuration. 
36   * <p>
37   * Configuration Properties:
38   * <dl>
39   *   <dt>${name|hierarchy}.LEVEL=(ALL|DEBUG|INFO|WARN|OFF)</dt>
40   *   <dd>
41   *   Sets the level that the Logger should log at.<br>
42   *   Names can be a package name, or a fully qualified class name.<br>
43   *   Default: INFO<br>
44   *   <br>
45   *   Examples:
46   *   <dl>
47   *   <dt>org.eclipse.jetty.LEVEL=WARN</dt>
48   *   <dd>indicates that all of the jetty specific classes, in any package that 
49   *   starts with <code>org.eclipse.jetty</code> should log at level WARN.</dd>
50   *   <dt>org.eclipse.jetty.io.ChannelEndPoint.LEVEL=ALL</dt>
51   *   <dd>indicates that the specific class, ChannelEndPoint, should log all
52   *   logging events that it can generate, including DEBUG, INFO, WARN (and even special
53   *   internally ignored exception cases).</dd>
54   *   </dl>  
55   *   </dd>
56   *   
57   *   <dt>${name}.SOURCE=(true|false)</dt>
58   *   <dd>
59   *   Logger specific, attempt to print the java source file name and line number
60   *   where the logging event originated from.<br>
61   *   Name must be a fully qualified class name (package name hierarchy is not supported
62   *   by this configurable)<br>
63   *   Warning: this is a slow operation and will have an impact on performance!<br>
64   *   Default: false
65   *   </dd>
66   *   
67   *   <dt>${name}.STACKS=(true|false)</dt>
68   *   <dd>
69   *   Logger specific, control the display of stacktraces.<br>
70   *   Name must be a fully qualified class name (package name hierarchy is not supported
71   *   by this configurable)<br>
72   *   Default: true
73   *   </dd>
74   *   
75   *   <dt>org.eclipse.jetty.util.log.stderr.SOURCE=(true|false)</dt>
76   *   <dd>Special Global Configuration, attempt to print the java source file name and line number
77   *   where the logging event originated from.<br>
78   *   Default: false
79   *   </dd>
80   *   
81   *   <dt>org.eclipse.jetty.util.log.stderr.LONG=(true|false)</dt>
82   *   <dd>Special Global Configuration, when true, output logging events to STDERR using
83   *   long form, fully qualified class names.  when false, use abbreviated package names<br>
84   *   Default: false
85   *   </dd>
86   *   <dt>org.eclipse.jetty.util.log.stderr.ESCAPE=(true|false)</dt>
87   *   <dd>Global Configuration, when true output logging events to STDERR are always
88   *   escaped so that control characters are replaced with '?";  '\r' with '&lt;' and '\n' replaced '|'<br>
89   *   Default: true
90   *   </dd>
91   * </dl>
92   */
93  @ManagedObject("Jetty StdErr Logging Implementation")
94  public class StdErrLog extends AbstractLogger
95  {
96      private static final String EOL = System.getProperty("line.separator");
97      // Do not change output format lightly, people rely on this output format now.
98      private static int __tagpad = Integer.parseInt(Log.__props.getProperty("org.eclipse.jetty.util.log.StdErrLog.TAG_PAD","0"));
99      private static DateCache _dateCache;
100 
101     private final static boolean __source = Boolean.parseBoolean(Log.__props.getProperty("org.eclipse.jetty.util.log.SOURCE",
102             Log.__props.getProperty("org.eclipse.jetty.util.log.stderr.SOURCE","false")));
103     private final static boolean __long = Boolean.parseBoolean(Log.__props.getProperty("org.eclipse.jetty.util.log.stderr.LONG","false"));
104     private final static boolean __escape = Boolean.parseBoolean(Log.__props.getProperty("org.eclipse.jetty.util.log.stderr.ESCAPE","true"));
105     
106     static
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 void setTagPad(int pad)
131     {
132         __tagpad=pad;
133     }
134     
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     public static int getLoggingLevel(Properties props,String name)
151     {
152         int level = lookupLoggingLevel(props,name);
153         if (level==LEVEL_DEFAULT)
154         {
155             level = lookupLoggingLevel(props,"log");
156             if (level==LEVEL_DEFAULT)
157                 level=LEVEL_INFO;
158         }
159         return level;
160     }
161     
162     
163     /**
164      * Obtain a StdErrLog reference for the specified class, a convenience method used most often during testing to allow for control over a specific logger.
165      * <p>
166      * Must be actively using StdErrLog as the Logger implementation.
167      * 
168      * @param clazz
169      *            the Class reference for the logger to use.
170      * @return the StdErrLog logger
171      * @throws RuntimeException
172      *             if StdErrLog is not the active Logger implementation.
173      */
174     public static StdErrLog getLogger(Class<?> clazz)
175     {
176         Logger log = Log.getLogger(clazz);
177         if (log instanceof StdErrLog)
178         {
179             return (StdErrLog)log;
180         }
181         throw new RuntimeException("Logger for " + clazz + " is not of type StdErrLog");
182     }
183 
184     /**
185      * Construct an anonymous StdErrLog (no name).
186      * <p>
187      * NOTE: Discouraged usage!
188      */
189     public StdErrLog()
190     {
191         this(null);
192     }
193 
194     /**
195      * Construct a named StdErrLog using the {@link Log} defined properties
196      * 
197      * @param name
198      *            the name of the logger
199      */
200     public StdErrLog(String name)
201     {
202         this(name,null);
203     }
204 
205     /**
206      * Construct a named Logger using the provided properties to configure logger.
207      * 
208      * @param name
209      *            the name of the logger
210      * @param props
211      *            the configuration properties
212      */
213     public StdErrLog(String name, Properties props)
214     {
215         if (props!=null && props!=Log.__props)
216             Log.__props.putAll(props);
217         _name = name == null?"":name;
218         _abbrevname = condensePackageString(this._name);
219         _level = getLoggingLevel(Log.__props,this._name);
220         _configuredLevel = _level;
221 
222         try
223         {
224             String source = getLoggingProperty(Log.__props,_name,"SOURCE");
225             _source = source==null?__source:Boolean.parseBoolean(source);
226         }
227         catch (AccessControlException ace)
228         {
229             _source = __source;
230         }
231 
232         try
233         {
234             // allow stacktrace display to be controlled by properties as well
235             String stacks = getLoggingProperty(Log.__props,_name,"STACKS");
236             _hideStacks = stacks==null?false:!Boolean.parseBoolean(stacks);
237         }
238         catch (AccessControlException ignore)
239         {
240             /* ignore */
241         }        
242     }
243 
244     public String getName()
245     {
246         return _name;
247     }
248 
249     public void setPrintLongNames(boolean printLongNames)
250     {
251         this._printLongNames = printLongNames;
252     }
253 
254     public boolean isPrintLongNames()
255     {
256         return this._printLongNames;
257     }
258 
259     public boolean isHideStacks()
260     {
261         return _hideStacks;
262     }
263 
264     public void setHideStacks(boolean hideStacks)
265     {
266         _hideStacks = hideStacks;
267     }
268 
269     /* ------------------------------------------------------------ */
270     /**
271      * Is the source of a log, logged
272      *
273      * @return true if the class, method, file and line number of a log is logged.
274      */
275     public boolean isSource()
276     {
277         return _source;
278     }
279 
280     /* ------------------------------------------------------------ */
281     /**
282      * Set if a log source is logged.
283      *
284      * @param source
285      *            true if the class, method, file and line number of a log is logged.
286      */
287     public void setSource(boolean source)
288     {
289         _source = source;
290     }
291 
292     public void warn(String msg, Object... args)
293     {
294         if (_level <= LEVEL_WARN)
295         {
296             StringBuilder buffer = new StringBuilder(64);
297             format(buffer,":WARN:",msg,args);
298             (_stderr==null?System.err:_stderr).println(buffer);
299         }
300     }
301 
302     public void warn(Throwable thrown)
303     {
304         warn("",thrown);
305     }
306 
307     public void warn(String msg, Throwable thrown)
308     {
309         if (_level <= LEVEL_WARN)
310         {
311             StringBuilder buffer = new StringBuilder(64);
312             format(buffer,":WARN:",msg,thrown);
313             (_stderr==null?System.err:_stderr).println(buffer);
314         }
315     }
316 
317     public void info(String msg, Object... args)
318     {
319         if (_level <= LEVEL_INFO)
320         {
321             StringBuilder buffer = new StringBuilder(64);
322             format(buffer,":INFO:",msg,args);
323             (_stderr==null?System.err:_stderr).println(buffer);
324         }
325     }
326 
327     public void info(Throwable thrown)
328     {
329         info("",thrown);
330     }
331 
332     public void info(String msg, Throwable thrown)
333     {
334         if (_level <= LEVEL_INFO)
335         {
336             StringBuilder buffer = new StringBuilder(64);
337             format(buffer,":INFO:",msg,thrown);
338             (_stderr==null?System.err:_stderr).println(buffer);
339         }
340     }
341 
342     @ManagedAttribute("is debug enabled for root logger Log.LOG")
343     public boolean isDebugEnabled()
344     {
345         return (_level <= LEVEL_DEBUG);
346     }
347 
348     /**
349      * Legacy interface where a programmatic configuration of the logger level
350      * is done as a wholesale approach.
351      */
352     @Override
353     public void setDebugEnabled(boolean enabled)
354     {
355         if (enabled)
356         {
357             this._level = LEVEL_DEBUG;
358 
359             for (Logger log : Log.getLoggers().values())
360             {                
361                 if (log.getName().startsWith(getName()) && log instanceof StdErrLog)
362                     ((StdErrLog)log).setLevel(LEVEL_DEBUG);
363             }
364         }
365         else
366         {
367             this._level = this._configuredLevel;
368 
369             for (Logger log : Log.getLoggers().values())
370             {
371                 if (log.getName().startsWith(getName()) && log instanceof StdErrLog)
372                     ((StdErrLog)log).setLevel(((StdErrLog)log)._configuredLevel);
373             }
374         }
375     }
376 
377     public int getLevel()
378     {
379         return _level;
380     }
381 
382     /**
383      * Set the level for this logger.
384      * <p>
385      * Available values ({@link StdErrLog#LEVEL_ALL}, {@link StdErrLog#LEVEL_DEBUG}, {@link StdErrLog#LEVEL_INFO},
386      * {@link StdErrLog#LEVEL_WARN})
387      *
388      * @param level
389      *            the level to set the logger to
390      */
391     public void setLevel(int level)
392     {
393         this._level = level;
394     }
395 
396     public void setStdErrStream(PrintStream stream)
397     {
398         this._stderr = stream==System.err?null:stream;
399     }
400 
401     public void debug(String msg, Object... args)
402     {
403         if (_level <= LEVEL_DEBUG)
404         {
405             StringBuilder buffer = new StringBuilder(64);
406             format(buffer,":DBUG:",msg,args);
407             (_stderr==null?System.err:_stderr).println(buffer);
408         }
409     }
410 
411     public void debug(String msg, long arg)
412     {
413         if (isDebugEnabled())
414         {
415             StringBuilder buffer = new StringBuilder(64);
416             format(buffer,":DBUG:",msg,arg);
417             (_stderr==null?System.err:_stderr).println(buffer);
418         }
419     }
420     
421     public void debug(Throwable thrown)
422     {
423         debug("",thrown);
424     }
425 
426     public void debug(String msg, Throwable thrown)
427     {
428         if (_level <= LEVEL_DEBUG)
429         {
430             StringBuilder buffer = new StringBuilder(64);
431             format(buffer,":DBUG:",msg,thrown);
432             (_stderr==null?System.err:_stderr).println(buffer);
433         }
434     }
435 
436     private void format(StringBuilder buffer, String level, String msg, Object... args)
437     {
438         long now = System.currentTimeMillis();
439         int ms=(int)(now%1000);
440         String d = _dateCache.formatNow(now);
441         tag(buffer,d,ms,level);
442         format(buffer,msg,args);
443     }
444 
445     private void format(StringBuilder buffer, String level, String msg, Throwable thrown)
446     {
447         format(buffer,level,msg);
448         if (isHideStacks())
449         {
450             format(buffer,": "+String.valueOf(thrown));
451         }
452         else
453         {
454             format(buffer,thrown);
455         }
456     }
457 
458     private void tag(StringBuilder buffer, String d, int ms, String tag)
459     {
460         buffer.setLength(0);
461         buffer.append(d);
462         if (ms > 99)
463         {
464             buffer.append('.');
465         }
466         else if (ms > 9)
467         {
468             buffer.append(".0");
469         }
470         else
471         {
472             buffer.append(".00");
473         }
474         buffer.append(ms).append(tag);
475         
476         String name=_printLongNames?_name:_abbrevname;
477         String tname=Thread.currentThread().getName();
478 
479         int p=__tagpad>0?(name.length()+tname.length()-__tagpad):0;
480 
481         if (p<0)
482         {
483             buffer
484             .append(name)
485             .append(':')
486             .append("                                                  ",0,-p)
487             .append(tname);
488         }
489         else if (p==0)
490         {
491             buffer.append(name).append(':').append(tname);
492         }
493         buffer.append(':');
494         
495         if (_source)
496         {
497             Throwable source = new Throwable();
498             StackTraceElement[] frames = source.getStackTrace();
499             for (int i = 0; i < frames.length; i++)
500             {
501                 final StackTraceElement frame = frames[i];
502                 String clazz = frame.getClassName();
503                 if (clazz.equals(StdErrLog.class.getName()) || clazz.equals(Log.class.getName()))
504                 {
505                     continue;
506                 }
507                 if (!_printLongNames && clazz.startsWith("org.eclipse.jetty."))
508                 {
509                     buffer.append(condensePackageString(clazz));
510                 }
511                 else
512                 {
513                     buffer.append(clazz);
514                 }
515                 buffer.append('#').append(frame.getMethodName());
516                 if (frame.getFileName() != null)
517                 {
518                     buffer.append('(').append(frame.getFileName()).append(':').append(frame.getLineNumber()).append(')');
519                 }
520                 buffer.append(':');
521                 break;
522             }
523         }
524 
525         buffer.append(' ');
526     }
527 
528     private void format(StringBuilder builder, String msg, Object... args)
529     {
530         if (msg == null)
531         {
532             msg = "";
533             for (int i = 0; i < args.length; i++)
534             {
535                 msg += "{} ";
536             }
537         }
538         String braces = "{}";
539         int start = 0;
540         for (Object arg : args)
541         {
542             int bracesIndex = msg.indexOf(braces,start);
543             if (bracesIndex < 0)
544             {
545                 escape(builder,msg.substring(start));
546                 builder.append(" ");
547                 builder.append(arg);
548                 start = msg.length();
549             }
550             else
551             {
552                 escape(builder,msg.substring(start,bracesIndex));
553                 builder.append(String.valueOf(arg));
554                 start = bracesIndex + braces.length();
555             }
556         }
557         escape(builder,msg.substring(start));
558     }
559 
560     private void escape(StringBuilder builder, String string)
561     {
562         if (__escape)
563         {
564             for (int i = 0; i < string.length(); ++i)
565             {
566                 char c = string.charAt(i);
567                 if (Character.isISOControl(c))
568                 {
569                     if (c == '\n')
570                     {
571                         builder.append('|');
572                     }
573                     else if (c == '\r')
574                     {
575                         builder.append('<');
576                     }
577                     else
578                     {
579                         builder.append('?');
580                     }
581                 }
582                 else
583                 {
584                     builder.append(c);
585                 }
586             }
587         }
588         else
589             builder.append(string);
590     }
591 
592     protected void format(StringBuilder buffer, Throwable thrown)
593     {
594         format(buffer,thrown,"");
595     }
596     
597     protected void format(StringBuilder buffer, Throwable thrown, String indent)
598     {
599         if (thrown == null)
600         {
601             buffer.append("null");
602         }
603         else
604         {
605             buffer.append(EOL).append(indent);
606             format(buffer,thrown.toString());
607             StackTraceElement[] elements = thrown.getStackTrace();
608             for (int i = 0; elements != null && i < elements.length; i++)
609             {
610                 buffer.append(EOL).append(indent).append("\tat ");
611                 format(buffer,elements[i].toString());
612             }
613 
614             for (Throwable suppressed:thrown.getSuppressed())
615             {
616                 buffer.append(EOL).append(indent).append("Suppressed: ");
617                 format(buffer,suppressed,"\t|"+indent);
618             }
619             
620             Throwable cause = thrown.getCause();
621             if (cause != null && cause != thrown)
622             {
623                 buffer.append(EOL).append(indent).append("Caused by: ");
624                 format(buffer,cause,indent);
625             }
626         }
627     }
628 
629 
630     /**
631      * Create a Child Logger of this Logger.
632      */
633     @Override
634     protected Logger newLogger(String fullname)
635     {
636         StdErrLog logger = new StdErrLog(fullname);
637         // Preserve configuration for new loggers configuration
638         logger.setPrintLongNames(_printLongNames);
639         logger._stderr = this._stderr;
640 
641         // Force the child to have any programmatic configuration
642         if (_level!=_configuredLevel)
643             logger._level=_level;
644 
645         return logger;
646     }
647 
648     @Override
649     public String toString()
650     {
651         StringBuilder s = new StringBuilder();
652         s.append("StdErrLog:");
653         s.append(_name);
654         s.append(":LEVEL=");
655         switch (_level)
656         {
657             case LEVEL_ALL:
658                 s.append("ALL");
659                 break;
660             case LEVEL_DEBUG:
661                 s.append("DEBUG");
662                 break;
663             case LEVEL_INFO:
664                 s.append("INFO");
665                 break;
666             case LEVEL_WARN:
667                 s.append("WARN");
668                 break;
669             default:
670                 s.append("?");
671                 break;
672         }
673         return s.toString();
674     }
675 
676     public void ignore(Throwable ignored)
677     {
678         if (_level <= LEVEL_ALL)
679         {
680             StringBuilder buffer = new StringBuilder(64);
681             format(buffer,":IGNORED:","",ignored);
682             (_stderr==null?System.err:_stderr).println(buffer);
683         }
684     }
685 }