1 /*
2  * Licensed to the Apache Software Foundation (ASF) under one or more
3  * contributor license agreements.  See the NOTICE file distributed with
4  * this work for additional information regarding copyright ownership.
5  * The ASF licenses this file to You under the Apache License, Version 2.0
6  * (the "License"); you may not use this file except in compliance with
7  * the License.  You may obtain a copy of the License at
8  *
9  *      http://www.apache.org/licenses/LICENSE-2.0
10  *
11  * Unless required by applicable law or agreed to in writing, software
12  * distributed under the License is distributed on an "AS IS" BASIS,
13  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
14  * See the License for the specific language governing permissions and
15  * limitations under the License.
16  */
17 package org.apache.juli;
18
19 import java.io.PrintWriter;
20 import java.io.StringWriter;
21 import java.io.Writer;
22 import java.lang.management.ManagementFactory;
23 import java.lang.management.ThreadInfo;
24 import java.lang.management.ThreadMXBean;
25 import java.util.LinkedHashMap;
26 import java.util.Map;
27 import java.util.Map.Entry;
28 import java.util.logging.Formatter;
29 import java.util.logging.LogManager;
30 import java.util.logging.LogRecord;
31
32 /**
33  * Provides same information as default log format but on a single line to make
34  * it easier to grep the logs. The only exception is stacktraces which are
35  * always preceded by whitespace to make it simple to skip them.
36  */
37 /*
38  * Date processing based on AccessLogValve.
39  */
40 public class OneLineFormatter extends Formatter {
41
42     private static final String UNKNOWN_THREAD_NAME = "Unknown thread with ID ";
43     private static final Object threadMxBeanLock = new Object();
44     private static volatile ThreadMXBean threadMxBean = null;
45     private static final int THREAD_NAME_CACHE_SIZE = 10000;
46     private static ThreadLocal<ThreadNameCache> threadNameCache = new ThreadLocal<ThreadNameCache>() {
47         @Override
48         protected ThreadNameCache initialValue() {
49             return new ThreadNameCache(THREAD_NAME_CACHE_SIZE);
50         }
51     };
52
53     /* Timestamp format */
54     private static final String DEFAULT_TIME_FORMAT = "dd-MMM-yyyy HH:mm:ss.SSS";
55
56     /**
57      * The size of our global date format cache
58      */
59     private static final int globalCacheSize = 30;
60
61     /**
62      * The size of our thread local date format cache
63      */
64     private static final int localCacheSize = 5;
65
66     /**
67      * Thread local date format cache.
68      */
69     private ThreadLocal<DateFormatCache> localDateCache;
70
71     private volatile MillisHandling millisHandling = MillisHandling.APPEND;
72
73
74     public OneLineFormatter() {
75         String timeFormat = LogManager.getLogManager().getProperty(
76                 OneLineFormatter.class.getName() + ".timeFormat");
77         if (timeFormat == null) {
78             timeFormat = DEFAULT_TIME_FORMAT;
79         }
80         setTimeFormat(timeFormat);
81     }
82
83
84     /**
85      * Specify the time format to use for time stamps in log messages.
86      *
87      * @param timeFormat The format to use using the
88      *                   {@link java.text.SimpleDateFormat} syntax
89      */
90     public void setTimeFormat(final String timeFormat) {
91         final String cachedTimeFormat;
92
93         if (timeFormat.endsWith(".SSS")) {
94             cachedTimeFormat = timeFormat.substring(0,  timeFormat.length() - 4);
95             millisHandling = MillisHandling.APPEND;
96         } else if (timeFormat.contains("SSS")) {
97             millisHandling = MillisHandling.REPLACE_SSS;
98             cachedTimeFormat = timeFormat;
99         } else if (timeFormat.contains("SS")) {
100             millisHandling = MillisHandling.REPLACE_SS;
101             cachedTimeFormat = timeFormat;
102         } else if (timeFormat.contains("S")) {
103             millisHandling = MillisHandling.REPLACE_S;
104             cachedTimeFormat = timeFormat;
105         } else {
106             millisHandling = MillisHandling.NONE;
107             cachedTimeFormat = timeFormat;
108         }
109
110         final DateFormatCache globalDateCache =
111                 new DateFormatCache(globalCacheSize, cachedTimeFormat, null);
112         localDateCache = new ThreadLocal<DateFormatCache>() {
113             @Override
114             protected DateFormatCache initialValue() {
115                 return new DateFormatCache(localCacheSize, cachedTimeFormat, globalDateCache);
116             }
117         };
118     }
119
120
121     /**
122      * Obtain the format currently being used for time stamps in log messages.
123      *
124      * @return The current format in {@link java.text.SimpleDateFormat} syntax
125      */
126     public String getTimeFormat() {
127         return localDateCache.get().getTimeFormat();
128     }
129
130
131     @Override
132     public String format(LogRecord record) {
133         StringBuilder sb = new StringBuilder();
134
135         // Timestamp
136         addTimestamp(sb, record.getMillis());
137
138         // Severity
139         sb.append(' ');
140         sb.append(record.getLevel().getLocalizedName());
141
142         // Thread
143         sb.append(' ');
144         sb.append('[');
145         if (Thread.currentThread() instanceof AsyncFileHandler.LoggerThread) {
146             // If using the async handler can't get the thread name from the
147             // current thread.
148             sb.append(getThreadName(record.getThreadID()));
149         } else {
150             sb.append(Thread.currentThread().getName());
151         }
152         sb.append(']');
153
154         // Source
155         sb.append(' ');
156         sb.append(record.getSourceClassName());
157         sb.append('.');
158         sb.append(record.getSourceMethodName());
159
160         // Message
161         sb.append(' ');
162         sb.append(formatMessage(record));
163
164         // New line for next record
165         sb.append(System.lineSeparator());
166
167         // Stack trace
168         if (record.getThrown() != null) {
169             StringWriter sw = new StringWriter();
170             PrintWriter pw = new IndentingPrintWriter(sw);
171             record.getThrown().printStackTrace(pw);
172             pw.close();
173             sb.append(sw.getBuffer());
174         }
175
176         return sb.toString();
177     }
178
179     protected void addTimestamp(StringBuilder buf, long timestamp) {
180         String cachedTimeStamp = localDateCache.get().getFormat(timestamp);
181         if (millisHandling == MillisHandling.NONE) {
182             buf.append(cachedTimeStamp);
183         } else if (millisHandling == MillisHandling.APPEND) {
184             buf.append(cachedTimeStamp);
185             long frac = timestamp % 1000;
186             buf.append('.');
187             if (frac < 100) {
188                 if (frac < 10) {
189                     buf.append('0');
190                     buf.append('0');
191                 } else {
192                     buf.append('0');
193                 }
194             }
195             buf.append(frac);
196         } else {
197             // Some version of replace
198             long frac = timestamp % 1000;
199             // Formatted string may vary in length so the insert point may vary
200             int insertStart = cachedTimeStamp.indexOf(DateFormatCache.MSEC_PATTERN);
201             buf.append(cachedTimeStamp.subSequence(0, insertStart));
202             if (frac < 100 && millisHandling == MillisHandling.REPLACE_SSS) {
203                 buf.append('0');
204                 if (frac < 10) {
205                     buf.append('0');
206                 }
207             } else if (frac < 10 && millisHandling == MillisHandling.REPLACE_SS) {
208                 buf.append('0');
209             }
210             buf.append(frac);
211             if (millisHandling == MillisHandling.REPLACE_SSS) {
212                 buf.append(cachedTimeStamp.substring(insertStart + 3));
213             } else if (millisHandling == MillisHandling.REPLACE_SS) {
214                 buf.append(cachedTimeStamp.substring(insertStart + 2));
215             } else {
216                 buf.append(cachedTimeStamp.substring(insertStart + 1));
217             }
218         }
219     }
220
221
222     /**
223      * LogRecord has threadID but no thread name.
224      * LogRecord uses an int for thread ID but thread IDs are longs.
225      * If the real thread ID > (Integer.MAXVALUE / 2) LogRecord uses it's own
226      * ID in an effort to avoid clashes due to overflow.
227      * <p>
228      * Words fail me to describe what I think of the design decision to use an
229      * int in LogRecord for a long value and the resulting mess that follows.
230      */
231     private static String getThreadName(int logRecordThreadId) {
232         Map<Integer,String> cache = threadNameCache.get();
233         String result = null;
234
235         if (logRecordThreadId > (Integer.MAX_VALUE / 2)) {
236             result = cache.get(Integer.valueOf(logRecordThreadId));
237         }
238
239         if (result != null) {
240             return result;
241         }
242
243         if (logRecordThreadId > Integer.MAX_VALUE / 2) {
244             result = UNKNOWN_THREAD_NAME + logRecordThreadId;
245         } else {
246             // Double checked locking OK as threadMxBean is volatile
247             if (threadMxBean == null) {
248                 synchronized (threadMxBeanLock) {
249                     if (threadMxBean == null) {
250                         threadMxBean = ManagementFactory.getThreadMXBean();
251                     }
252                 }
253             }
254             ThreadInfo threadInfo =
255                     threadMxBean.getThreadInfo(logRecordThreadId);
256             if (threadInfo == null) {
257                 return Long.toString(logRecordThreadId);
258             }
259             result = threadInfo.getThreadName();
260         }
261
262         cache.put(Integer.valueOf(logRecordThreadId), result);
263
264         return result;
265     }
266
267
268     private static class ThreadNameCache extends LinkedHashMap<Integer,String> {
269
270         private static final long serialVersionUID = 1L;
271
272         private final int cacheSize;
273
274         public ThreadNameCache(int cacheSize) {
275             this.cacheSize = cacheSize;
276         }
277
278         @Override
279         protected boolean removeEldestEntry(Entry<Integer, String> eldest) {
280             return (size() > cacheSize);
281         }
282     }
283
284
285     /*
286      * Minimal implementation to indent the printing of stack traces. This
287      * implementation depends on Throwable using WrappedPrintWriter.
288      */
289     private static class IndentingPrintWriter extends PrintWriter {
290
291         public IndentingPrintWriter(Writer out) {
292             super(out);
293         }
294
295         @Override
296         public void println(Object x) {
297             super.print('\t');
298             super.println(x);
299         }
300     }
301
302
303     private static enum MillisHandling {
304         NONE,
305         APPEND,
306         REPLACE_S,
307         REPLACE_SS,
308         REPLACE_SSS,
309     }
310 }
311