View Javadoc
1   /*
2    * Copyright (c) 2001-2017, Zoltan Farkas All Rights Reserved.
3    *
4    * This library is free software; you can redistribute it and/or
5    * modify it under the terms of the GNU Lesser General Public
6    * License as published by the Free Software Foundation; either
7    * version 2.1 of the License, or (at your option) any later version.
8    *
9    * This library is distributed in the hope that it will be useful,
10   * but WITHOUT ANY WARRANTY; without even the implied warranty of
11   * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
12   * GNU General Public License for more details.
13   *
14   * You should have received a copy of the GNU Lesser General Public
15   * License along with this program; if not, write to the Free Software
16   * Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA  02111-1307, USA.
17   *
18   * Additionally licensed with:
19   *
20   * Licensed under the Apache License, Version 2.0 (the "License");
21   * you may not use this file except in compliance with the License.
22   * You may obtain a copy of the License at
23   *
24   *      http://www.apache.org/licenses/LICENSE-2.0
25   *
26   * Unless required by applicable law or agreed to in writing, software
27   * distributed under the License is distributed on an "AS IS" BASIS,
28   * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
29   * See the License for the specific language governing permissions and
30   * limitations under the License.
31   */
32  package org.spf4j.log;
33  
34  import com.google.common.cache.CacheBuilder;
35  import com.google.common.cache.CacheLoader;
36  import com.google.common.cache.LoadingCache;
37  import edu.umd.cs.findbugs.annotations.SuppressFBWarnings;
38  import java.io.IOException;
39  import java.io.UncheckedIOException;
40  import java.lang.ref.Reference;
41  import java.lang.ref.SoftReference;
42  import java.lang.reflect.Field;
43  import java.security.AccessController;
44  import java.security.PrivilegedAction;
45  import java.util.Locale;
46  import java.util.MissingResourceException;
47  import java.util.ResourceBundle;
48  import java.util.logging.Handler;
49  import java.util.logging.Level;
50  import java.util.logging.LogManager;
51  import java.util.logging.LogRecord;
52  import javax.annotation.Nonnull;
53  import javax.annotation.Nullable;
54  
55  import org.slf4j.Logger;
56  import org.slf4j.LoggerFactory;
57  import org.slf4j.spi.LocationAwareLogger;
58  import org.spf4j.base.Arrays;
59  import org.spf4j.base.Pair;
60  import org.spf4j.base.avro.Method;
61  import org.spf4j.text.MessageFormat;
62  
63  /**
64   * <p>
65   * Bridge/route all JUL log records to the SLF4J API.</p>
66   * <p>
67   * Implementation based on jul-to-slf4j bridge but at least 20% faster. Speed improvements come from using spf4j
68   * improved MessageFormatter + code cleanup. Also unlike jul-to-slf4j the sorce class and source method information is
69   * not being dropped. </p>
70   * <p>
71   * Implementation is interchangeable with the jul-to-slf4j implementation </p>
72   *
73   */
74  public final class SLF4JBridgeHandler extends Handler {
75  
76    private static final String FQCN = java.util.logging.Logger.class.getName();
77    private static final String UNKNOWN_LOGGER_NAME = "unknown.jul.logger";
78  
79    private static final int TRACE_LEVEL_THRESHOLD = Level.FINEST.intValue();
80    private static final int DEBUG_LEVEL_THRESHOLD = Level.FINE.intValue();
81    private static final int INFO_LEVEL_THRESHOLD = Level.INFO.intValue();
82    private static final int WARN_LEVEL_THRESHOLD = Level.WARNING.intValue();
83  
84    private static final ThreadLocal<Reference<StringBuilder>> SB = new
85            ThreadLocal<Reference<StringBuilder>>() {
86      @Override
87      protected Reference<StringBuilder> initialValue() {
88        return new SoftReference<>(new StringBuilder(64));
89      }
90  
91    };
92  
93    private static final MessageFormat INVALID_FORMAT = new MessageFormat("SPF4J Invalid Message Format");
94  
95    private static class Lazy {
96      private static final LoadingCache<Locale, LoadingCache<String, MessageFormat>> LOCALIZED_FORMAT_CACHE
97            = CacheBuilder.newBuilder()
98                    .build(new CacheLoader<Locale, LoadingCache<String, MessageFormat>>() {
99                      @Override
100                     public LoadingCache<String, MessageFormat> load(final Locale locale) throws Exception {
101                       return CacheBuilder.newBuilder()
102                               .maximumSize(Integer.getInteger("spf4j.julBridge.MaxFormatCacheSize",
103                                       1024)).build(new CacheLoader<String, MessageFormat>() {
104                                 @Override
105                                 public MessageFormat load(final String key) {
106                                   try {
107                                     return new MessageFormat(key, locale);
108                                   } catch (IllegalArgumentException ex) {
109                                     // certain loggers extend LogMessage with printf syntax...
110                                     LoggerFactory.getLogger(Lazy.class).trace("Unable to forrmat {}", key, ex);
111                                     return INVALID_FORMAT;
112                                   }
113                                 }
114                               });
115                     }
116                   }
117                   );
118   }
119 
120   private static final LoadingCache<String, MessageFormat> FORMAT_CACHE
121           = CacheBuilder.newBuilder()
122                   .maximumSize(Integer.getInteger("spf4j.julBridge.MaxFormatCacheSize",
123                   1024)).build(new CacheLoader<String, MessageFormat>() {
124             @Override
125             public MessageFormat load(final String key) {
126               try {
127                 return new MessageFormat(key);
128               } catch (IllegalArgumentException ex) {
129                 // certain loggers extend LogMessage with printf syntax...
130                 LoggerFactory.getLogger(SLF4JBridgeHandler.class).trace("Unable to forrmat {}", key, ex);
131                 return INVALID_FORMAT;
132               }
133             }
134           });
135 
136   private static final boolean ALWAYS_TRY_INFER = Boolean.getBoolean("spf4j.jul2slf4jBridge.alwaysTryInferSource");
137 
138   /**
139    * Need this to avoid source class and method inference. (which is expensive)
140    * @see https://bugs.java.com/bugdatabase/view_bug.do?bug_id=JDK-8244321
141    */
142   @Nullable
143   private static final Field NEED_INFER;
144 
145   static {
146     NEED_INFER = AccessController.doPrivileged(new PrivilegedAction<Field>() {
147       @Override
148       public Field run() {
149         try {
150           Field declaredField = LogRecord.class.getDeclaredField("needToInferCaller");
151           declaredField.setAccessible(true);
152           return declaredField;
153         } catch (NoSuchFieldException | SecurityException ex) {
154           LoggerFactory.getLogger(SLF4JBridgeHandler.class)
155                   .debug("jul to slf4j bridge will not differentiate between computed caller info and provided", ex);
156           return null;
157         }
158       }
159     });
160   }
161 
162   /**
163    * Adds a SLF4JBridgeHandler instance to jul's root logger.
164    *
165    * This handler will redirect j.u.l. logging to SLF4J. However, only logs enabled in j.u.l. will be redirected. For
166    * example, if a log statement invoking a j.u.l. logger is disabled, then the corresponding non-event will
167    * <em>not</em>
168    * reach SLF4JBridgeHandler and cannot be redirected.
169    */
170   public static void install() {
171     getRootLogger().addHandler(new SLF4JBridgeHandler());
172   }
173 
174   private static java.util.logging.Logger getRootLogger() {
175     return LogManager.getLogManager().getLogger("");
176   }
177 
178   /**
179    * Removes previously installed SLF4JBridgeHandler instances. See also {@link #install()}.
180    *
181    * @throws SecurityException A <code>SecurityException</code> is thrown, if a security manager exists and if the
182    * caller does not have LoggingPermission("control").
183    */
184   public static void uninstall() {
185     java.util.logging.Logger rootLogger = getRootLogger();
186     Handler[] handlers = rootLogger.getHandlers();
187     for (int i = 0; i < handlers.length; i++) {
188       if (handlers[i] instanceof SLF4JBridgeHandler) {
189         rootLogger.removeHandler(handlers[i]);
190       }
191     }
192   }
193 
194   /**
195    * Returns true if SLF4JBridgeHandler has been previously installed, returns false otherwise.
196    *
197    * @return true if SLF4JBridgeHandler is already installed, false other wise
198    * @throws SecurityException
199    */
200   public static boolean isInstalled() {
201     java.util.logging.Logger rootLogger = getRootLogger();
202     Handler[] handlers = rootLogger.getHandlers();
203     for (int i = 0; i < handlers.length; i++) {
204       if (handlers[i] instanceof SLF4JBridgeHandler) {
205         return true;
206       }
207     }
208     return false;
209   }
210 
211   /**
212    * Invoking this method removes/unregisters/detaches all handlers currently attached to the root logger
213    */
214   public static void removeHandlersForRootLogger() {
215     java.util.logging.Logger rootLogger = getRootLogger();
216     Handler[] handlers = rootLogger.getHandlers();
217     for (int i = 0; i < handlers.length; i++) {
218       rootLogger.removeHandler(handlers[i]);
219     }
220   }
221 
222   @Override
223   public void close() {
224     // NOOP
225   }
226 
227   @Override
228   public void flush() {
229     // NOOP
230   }
231 
232   /**
233    * Return the Logger instance that will be used for logging.
234    */
235   private static Logger getSLF4JLogger(final LogRecord record) {
236     String name = record.getLoggerName();
237     if (name == null) {
238       name = UNKNOWN_LOGGER_NAME;
239     }
240     return LoggerFactory.getLogger(name);
241   }
242 
243   private static void callLocationAwareLogger(final LocationAwareLogger lal, final LogRecord record) {
244     int julLevelValue = record.getLevel().intValue();
245     int slf4jLevel;
246     if (julLevelValue <= TRACE_LEVEL_THRESHOLD) {
247       slf4jLevel = LocationAwareLogger.TRACE_INT;
248     } else if (julLevelValue <= DEBUG_LEVEL_THRESHOLD) {
249       slf4jLevel = LocationAwareLogger.DEBUG_INT;
250     } else if (julLevelValue <= INFO_LEVEL_THRESHOLD) {
251       slf4jLevel = LocationAwareLogger.INFO_INT;
252     } else if (julLevelValue <= WARN_LEVEL_THRESHOLD) {
253       slf4jLevel = LocationAwareLogger.WARN_INT;
254     } else {
255       slf4jLevel = LocationAwareLogger.ERROR_INT;
256     }
257     Pair<String, Object[]> messageArgs = getMessageI18N(record);
258     Method m = getSourceMethodInfo(record);
259     if (m != null) {
260       lal.log(null, m.toString(), slf4jLevel, messageArgs.getFirst(), messageArgs.getSecond(), record.getThrown());
261     } else {
262       lal.log(null, FQCN, slf4jLevel, messageArgs.getFirst(), messageArgs.getSecond(), record.getThrown());
263     }
264   }
265 
266   @SuppressFBWarnings("UCC_UNRELATED_COLLECTION_CONTENTS") // nature of log args
267   private static void callPlainSLF4JLogger(final Logger slf4jLogger, final LogRecord record) {
268     Pair<String, Object[]> message = getMessageI18N(record);
269     Object[] args = message.getSecond();
270     if (args == null || args.length == 0) {
271       logEfficient(message.getFirst(), record, slf4jLogger);
272     } else {
273       int julLevelValue = record.getLevel().intValue();
274       Throwable thrown = record.getThrown();
275       Method m = getSourceMethodInfo(record);
276       Object[] pargs;
277       if (m == null) {
278         if (thrown == null) {
279           pargs = args;
280         } else {
281           pargs = java.util.Arrays.copyOf(args, args.length + 1);
282           pargs[args.length] = thrown;
283         }
284       } else {
285         if (thrown == null) {
286           pargs = java.util.Arrays.copyOf(args, args.length + 1);
287           pargs[args.length] = m;
288         } else {
289           pargs = java.util.Arrays.copyOf(args, args.length + 2);
290           pargs[args.length] = m;
291           pargs[args.length + 1] = thrown;
292         }
293       }
294       if (julLevelValue <= TRACE_LEVEL_THRESHOLD) {
295         slf4jLogger.trace(message.getFirst(), pargs);
296       } else if (julLevelValue <= DEBUG_LEVEL_THRESHOLD) {
297         slf4jLogger.debug(message.getFirst(), pargs);
298       } else if (julLevelValue <= INFO_LEVEL_THRESHOLD) {
299         slf4jLogger.info(message.getFirst(), pargs);
300       } else if (julLevelValue <= WARN_LEVEL_THRESHOLD) {
301         slf4jLogger.warn(message.getFirst(), pargs);
302       } else {
303         slf4jLogger.error(message.getFirst(), pargs);
304       }
305 
306     }
307   }
308 
309   public static void logEfficient(final String i18nMessage,
310           final LogRecord record, final Logger slf4jLogger) {
311     int julLevelValue = record.getLevel().intValue();
312     Throwable thrown = record.getThrown();
313     Method m = getSourceMethodInfo(record);
314     if (thrown != null) {
315       if (julLevelValue <= TRACE_LEVEL_THRESHOLD) {
316         if (m != null) {
317           slf4jLogger.trace(i18nMessage, m, thrown);
318         } else {
319           slf4jLogger.trace(i18nMessage, thrown);
320         }
321       } else if (julLevelValue <= DEBUG_LEVEL_THRESHOLD) {
322         if (m != null) {
323           slf4jLogger.debug(i18nMessage, m, thrown);
324         } else {
325           slf4jLogger.debug(i18nMessage, thrown);
326         }
327       } else if (julLevelValue <= INFO_LEVEL_THRESHOLD) {
328         if (m != null) {
329           slf4jLogger.info(i18nMessage, m, thrown);
330         } else {
331           slf4jLogger.info(i18nMessage, thrown);
332         }
333       } else if (julLevelValue <= WARN_LEVEL_THRESHOLD) {
334         if (m != null) {
335           slf4jLogger.warn(i18nMessage, m, thrown);
336         } else {
337           slf4jLogger.warn(i18nMessage, thrown);
338         }
339       } else {
340         if (m != null) {
341           slf4jLogger.error(i18nMessage, m, thrown);
342         } else {
343           slf4jLogger.error(i18nMessage, thrown);
344         }
345       }
346     } else {
347       if (julLevelValue <= TRACE_LEVEL_THRESHOLD) {
348         if (m != null) {
349           slf4jLogger.trace(i18nMessage, m);
350         } else {
351           slf4jLogger.trace(i18nMessage);
352         }
353       } else if (julLevelValue <= DEBUG_LEVEL_THRESHOLD) {
354         if (m != null) {
355           slf4jLogger.debug(i18nMessage, m);
356         } else {
357           slf4jLogger.debug(i18nMessage);
358         }
359       } else if (julLevelValue <= INFO_LEVEL_THRESHOLD) {
360         if (m != null) {
361           slf4jLogger.info(i18nMessage, m);
362         } else {
363           slf4jLogger.info(i18nMessage);
364         }
365       } else if (julLevelValue <= WARN_LEVEL_THRESHOLD) {
366         if (m != null) {
367           slf4jLogger.warn(i18nMessage, m);
368         } else {
369           slf4jLogger.warn(i18nMessage);
370         }
371       } else {
372         if (m != null) {
373           slf4jLogger.error(i18nMessage, m);
374         } else {
375           slf4jLogger.error(i18nMessage);
376         }
377       }
378     }
379   }
380 
381   @Nullable
382   public static Method getSourceMethodInfo(final LogRecord record) {
383     Method m;
384     try {
385       if (ALWAYS_TRY_INFER || (NEED_INFER != null && !NEED_INFER.getBoolean(record))) {
386         m = new Method(record.getSourceClassName(), record.getSourceMethodName());
387       } else {
388         m = null;
389       }
390     } catch (IllegalArgumentException | IllegalAccessException ex) {
391       throw new RuntimeException(ex);
392     }
393     return m;
394   }
395 
396   /**
397    * Get the record's message, possibly via a resource bundle.
398    *
399    * @param record
400    * @return
401    */
402   @Nonnull
403   private static Pair<String, Object[]> getMessageI18N(final LogRecord record) {
404     String message = record.getMessage();
405     if (message == null) {
406       return Pair.of("", record.getParameters());
407     }
408 
409     ResourceBundle bundle = record.getResourceBundle();
410     if (bundle != null) {
411       try {
412         message = bundle.getString(message);
413       } catch (MissingResourceException e) {
414       }
415     }
416     Object[] params = record.getParameters();
417     if (params != null && params.length > 0) {
418       StringBuilder msg = SB.get().get();
419       if (msg == null) {
420         msg = new StringBuilder(64);
421         SB.set(new SoftReference<>(msg));
422       } else  {
423         msg.setLength(0);
424       }
425       try {
426         boolean[] used;
427         try {
428           MessageFormat msgFormat;
429           if (bundle == null) {
430             msgFormat = FORMAT_CACHE.getUnchecked(message);
431           } else {
432             msgFormat = Lazy.LOCALIZED_FORMAT_CACHE.getUnchecked(bundle.getLocale()).getUnchecked(message);
433           }
434           if (msgFormat != INVALID_FORMAT) {
435             used =  msgFormat.format(params, msg);
436           } else {
437             // Some libraries like jboss log manager embeded do unkosher stuff,
438             // like printf style formatting see ExtLogRecord...
439             return Pair.of(record.getMessage(), record.getParameters());
440           }
441         } catch (IOException ex) {
442           throw new UncheckedIOException(ex);
443         }
444         int nrLeft = 0;
445         for (boolean u : used) {
446           if (!u) {
447             nrLeft++;
448           }
449         }
450         if (nrLeft == 0) {
451           return Pair.of(msg.toString(), Arrays.EMPTY_OBJ_ARRAY);
452         } else {
453           Object[] left = new Object[nrLeft];
454           for (int i = 0, j = 0; i < used.length; i++) {
455             if (!used[i]) {
456               left[j++] = params[i];
457             }
458           }
459           return Pair.of(msg.toString(), left);
460         }
461       } catch (IllegalArgumentException e) {
462         LoggerFactory.getLogger(SLF4JBridgeHandler.class).warn("Unable to format {} with {}", message, params, e);
463          return Pair.of(message, Arrays.EMPTY_OBJ_ARRAY);
464       }
465     } else {
466       return Pair.of(message, Arrays.EMPTY_OBJ_ARRAY);
467     }
468   }
469 
470   @Override
471   public void publish(final LogRecord record) {
472     try {
473       Logger slf4jLogger = getSLF4JLogger(record);
474       if (slf4jLogger instanceof LocationAwareLogger) {
475         callLocationAwareLogger((LocationAwareLogger) slf4jLogger, record);
476       } else {
477         callPlainSLF4JLogger(slf4jLogger, record);
478       }
479     } catch (RuntimeException ex) {
480       LoggerFactory.getLogger(SLF4JBridgeHandler.class).warn("Unable to publish {}", record, ex);
481     }
482   }
483 
484 }