Warum ist es nicht empfehlenswert, LoggerFactory.getLogger(...) jedes Mal aufzurufen?

Question

Ich habe tonnenweise Beiträge und Dokumente (auf dieser Website und anderswo) gelesen, die darauf hinweisen, dass das empfohlene Muster für die SFL4J-Protokollierung lautet:

public class MyClass {
    final static Logger logger = LoggerFactory.getLogger(MyClass.class);

    public void myMethod() {
        //do some stuff
        logger.debug("blah blah blah");
    }
}

Mein Chef zieht es vor, dass wir nur einen Wrapper verwenden, um Log-Aufrufe abzufangen und Boiler-Plate-Code zur Deklaration des Loggers in jeder Klasse zu vermeiden:

public class MyLoggerWrapper {
    public static void debug(Class clazz, String msg){
        LoggerFactory.getLogger(clazz).debug(msg));
    }
}

und sie einfach so zu verwenden:

public class MyClass {

    public void myMethod() {
        //do some stuff
        MyLoggerWrapper.debug(this.getClass(), "blah blah blah");
    }
}

Ich vermute, dass die Instanziierung eines Loggers jedes Mal, wenn wir protokollieren, etwas teuer ist, aber ich konnte kein Dokument finden, das diese Annahme unterstützt. Außerdem sagt er, dass das Framework (LogBack oder Log4J, wir entscheiden noch) die Logger "zwischenspeichern" wird und dass die Server auf jeden Fall weit unter ihrer Kapazität laufen, so dass dies kein Problem darstellt.

Kann mir jemand helfen, mögliche Probleme bei diesem Ansatz aufzuzeigen?

Answer 1

Hier ist eine Möglichkeit, die Protokollierung in Java 8 zu vereinfachen: Definieren Sie eine Schnittstelle, die dies für Sie erledigt. Zum Beispiel:

package logtesting;

import java.util.Arrays;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;

public interface Loggable { 
    enum LogLevel {
        TRACE, DEBUG, INFO, WARN, ERROR
    }

    LogLevel TRACE = LogLevel.TRACE;
    LogLevel DEBUG = LogLevel.DEBUG;
    LogLevel INFO = LogLevel.INFO;
    LogLevel WARN = LogLevel.WARN;
    LogLevel ERROR = LogLevel.ERROR;

    default void log(Object...args){
        log(DEBUG, args);
    }

    default void log(final LogLevel level, final Object...args){
        Logger logger = LoggerFactory.getLogger(this.getClass());
        switch(level){
        case ERROR:
            if (logger.isErrorEnabled()){
                logger.error(concat(args));
            }
            break;
        case WARN:
            if (logger.isWarnEnabled()){
                logger.warn(concat(args));
            }
            break;          
        case INFO:
            if (logger.isInfoEnabled()){
                logger.info(concat(args));
            }
        case TRACE:
            if (logger.isTraceEnabled()){
                logger.trace(concat(args));
            }
            break;
        default:
            if (logger.isDebugEnabled()){
                logger.debug(concat(args));
            }
            break;
        }
    }

    default String concat(final Object...args){ 
        return Arrays.stream(args).map(o->o.toString()).collect(Collectors.joining());
    }
}

Dann müssen Sie nur noch dafür sorgen, dass Ihre Klassen Folgendes erklären umsetzen Protokolliert und von dort aus können Sie Dinge tun wie:

log(INFO, "This is the first part ","of my string ","and this ","is the last");

Die Funktion log() kümmert sich um die Verkettung Ihrer Zeichenketten, aber erst nachdem sie auf "enabled" getestet hat. Standardmäßig wird nach Debug protokolliert, und wenn Sie nach Debug protokollieren möchten, können Sie das Argument LogLevel weglassen. Dies ist ein sehr einfaches Beispiel. Man könnte es beliebig verbessern, z.B. durch die Implementierung der einzelnen Methoden, d.h. error(), trace(), warn(), usw. Sie könnten auch einfach "logger" als eine Funktion implementieren, die einen Logger zurückgibt:

public interface Loggable {
    default Logger logger(){
        return LoggerFactory.getLogger(this.getClass());
    }
}

Und dann wird es ziemlich trivial, Ihren Logger zu benutzen:

logger().debug("This is my message");

Sie könnten es sogar voll funktionsfähig machen, indem Sie Delegatmethoden für alle Logger-Methoden erzeugen, so dass jede implementierende Klasse eine Instanz von Logger ist.

package logtesting;

import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.Marker;

public interface Loggable extends Logger {
    default Logger logger(){
        return LoggerFactory.getLogger(this.getClass());
    }

    default String getName() {
        return logger().getName();
    }

    default boolean isTraceEnabled() {
        return logger().isTraceEnabled();
    }

    default void trace(String msg) {
        logger().trace(msg);
    }

    default void trace(String format, Object arg) {
        logger().trace(format, arg);
    }

    default void trace(String format, Object arg1, Object arg2) {
        logger().trace(format, arg1, arg2);
    }

    default void trace(String format, Object... arguments) {
        logger().trace(format, arguments);
    }

    default void trace(String msg, Throwable t) {
        logger().trace(msg, t);
    }

    default boolean isTraceEnabled(Marker marker) {
        return logger().isTraceEnabled(marker);
    }

    default void trace(Marker marker, String msg) {
        logger().trace(marker, msg);
    }

    default void trace(Marker marker, String format, Object arg) {
        logger().trace(marker, format, arg);
    }

    default void trace(Marker marker, String format, Object arg1, Object arg2) {
        logger().trace(marker, format, arg1, arg2);
    }

    default void trace(Marker marker, String format, Object... argArray) {
        logger().trace(marker, format, argArray);
    }

    default void trace(Marker marker, String msg, Throwable t) {
        logger().trace(marker, msg, t);
    }

    default boolean isDebugEnabled() {
        return logger().isDebugEnabled();
    }

    default void debug(String msg) {
        logger().debug(msg);
    }

    default void debug(String format, Object arg) {
        logger().debug(format, arg);
    }

    default void debug(String format, Object arg1, Object arg2) {
        logger().debug(format, arg1, arg2);
    }

    default void debug(String format, Object... arguments) {
        logger().debug(format, arguments);
    }

    default void debug(String msg, Throwable t) {
        logger().debug(msg, t);
    }

    default boolean isDebugEnabled(Marker marker) {
        return logger().isDebugEnabled(marker);
    }

    default void debug(Marker marker, String msg) {
        logger().debug(marker, msg);
    }

    default void debug(Marker marker, String format, Object arg) {
        logger().debug(marker, format, arg);
    }

    default void debug(Marker marker, String format, Object arg1, Object arg2) {
        logger().debug(marker, format, arg1, arg2);
    }

    default void debug(Marker marker, String format, Object... arguments) {
        logger().debug(marker, format, arguments);
    }

    default void debug(Marker marker, String msg, Throwable t) {
        logger().debug(marker, msg, t);
    }

    default boolean isInfoEnabled() {
        return logger().isInfoEnabled();
    }

    default void info(String msg) {
        logger().info(msg);
    }

    default void info(String format, Object arg) {
        logger().info(format, arg);
    }

    default void info(String format, Object arg1, Object arg2) {
        logger().info(format, arg1, arg2);
    }

    default void info(String format, Object... arguments) {
        logger().info(format, arguments);
    }

    default void info(String msg, Throwable t) {
        logger().info(msg, t);
    }

    default boolean isInfoEnabled(Marker marker) {
        return logger().isInfoEnabled(marker);
    }

    default void info(Marker marker, String msg) {
        logger().info(marker, msg);
    }

    default void info(Marker marker, String format, Object arg) {
        logger().info(marker, format, arg);
    }

    default void info(Marker marker, String format, Object arg1, Object arg2) {
        logger().info(marker, format, arg1, arg2);
    }

    default void info(Marker marker, String format, Object... arguments) {
        logger().info(marker, format, arguments);
    }

    default void info(Marker marker, String msg, Throwable t) {
        logger().info(marker, msg, t);
    }

    default boolean isWarnEnabled() {
        return logger().isWarnEnabled();
    }

    default void warn(String msg) {
        logger().warn(msg);
    }

    default void warn(String format, Object arg) {
        logger().warn(format, arg);
    }

    default void warn(String format, Object... arguments) {
        logger().warn(format, arguments);
    }

    default void warn(String format, Object arg1, Object arg2) {
        logger().warn(format, arg1, arg2);
    }

    default void warn(String msg, Throwable t) {
        logger().warn(msg, t);
    }

    default boolean isWarnEnabled(Marker marker) {
        return logger().isWarnEnabled(marker);
    }

    default void warn(Marker marker, String msg) {
        logger().warn(marker, msg);
    }

    default void warn(Marker marker, String format, Object arg) {
        logger().warn(marker, format, arg);
    }

    default void warn(Marker marker, String format, Object arg1, Object arg2) {
        logger().warn(marker, format, arg1, arg2);
    }

    default void warn(Marker marker, String format, Object... arguments) {
        logger().warn(marker, format, arguments);
    }

    default void warn(Marker marker, String msg, Throwable t) {
        logger().warn(marker, msg, t);
    }

    default boolean isErrorEnabled() {
        return logger().isErrorEnabled();
    }

    default void error(String msg) {
        logger().error(msg);
    }

    default void error(String format, Object arg) {
        logger().error(format, arg);
    }

    default void error(String format, Object arg1, Object arg2) {
        logger().error(format, arg1, arg2);
    }

    default void error(String format, Object... arguments) {
        logger().error(format, arguments);
    }

    default void error(String msg, Throwable t) {
        logger().error(msg, t);
    }

    default boolean isErrorEnabled(Marker marker) {
        return logger().isErrorEnabled(marker);
    }

    default void error(Marker marker, String msg) {
        logger().error(marker, msg);
    }

    default void error(Marker marker, String format, Object arg) {
        logger().error(marker, format, arg);
    }

    default void error(Marker marker, String format, Object arg1, Object arg2) {
        logger().error(marker, format, arg1, arg2);
    }

    default void error(Marker marker, String format, Object... arguments) {
        logger().error(marker, format, arguments);
    }

    default void error(Marker marker, String msg, Throwable t) {
        logger().error(marker, msg, t);
    }
}

Natürlich bedeutet dies, wie bereits erwähnt, dass Sie jedes Mal, wenn Sie protokollieren, den Logger-Lookup-Prozess innerhalb Ihrer LoggerFactory durchlaufen müssen - es sei denn, Sie überschreiben die logger()-Methode... in diesem Fall können Sie es genauso gut auf die "empfohlene" Weise tun.

Answer 2

Wie angegeben aquí des SLF4J-Teams können Sie MethodLookup() verwenden, das im JDK 1.7 eingeführt wurde.

final static Logger logger = LoggerFactory.getLogger(MethodHandles.lookup().lookupClass());

Auf diese Weise können Sie auf die Klasse verweisen, ohne das Schlüsselwort "this" verwenden zu müssen.

Answer 3

Ich muss einfach sagen, dass das empfohlene Muster am einfachsten zu lesen und umzusetzen ist. Ich sehe keinen Grund, von diesem Muster abzuweichen. Vor allem keinen Nutzen.

Mein Hauptanliegen sind jedoch die bereits erwähnten Wachen. Ich würde nicht empfehlen, Ihre Protokolle explizit zu schützen, da dies bereits intern von log4j erledigt wird und eine Verdoppelung des Aufwands darstellt.

Laden Sie den Quellcode von log4j herunter und schauen Sie sich die Klassen Logger und Category an, um sich selbst davon zu überzeugen.

Answer 4

Nein. Nur, dass es den Aufrufstapel durcheinander bringt. Das unterbricht die Methoden, die es Ihnen ermöglichen, den Methodennamen und die Klasse des Codes zu sehen, der das Protokoll erstellt.

Sie können einen Blick auf den Jetty Web Container werfen, der eine eigene Abstraktion enthält, die auf slf4j aufbaut. Sehr schön.

Answer 5

Es gibt zwei Gründe, warum der Ansatz Ihres Chefs nicht das erreicht, was er glaubt.

Der kleinere Grund ist, dass der Aufwand für das Hinzufügen eines statischen Loggers vernachlässigbar ist. Schließlich ist die Einrichtung des Loggers Teil dieser ziemlich langen Sequenz:

• Finden Sie die Klasse, d.h. gehen Sie durch alle .jars und Verzeichnisse. Java-Code. Ziemlich großer Overhead aufgrund der Dateisystemaufrufe. Kann Hilfsobjekte erstellen, z.B. mit File .
• Laden des Bytecodes, d.h. Kopieren in eine Datenstruktur innerhalb der JVM. Nativer Code.
• Validieren Sie den Bytecode. Native Code.
• Linken des Bytecodes, d.h. alle Klassennamen im Bytecode durchlaufen und durch Zeiger auf die referenzierte Klasse ersetzen. Native Code.
• Statische Initialisierungen ausführen. Ausgelöst von nativem Code, sind die Initialisierer natürlich Java-Code. Der Logger wird hier erstellt.
• Nach einer Weile sollten Sie die Klasse vielleicht JIT-kompilieren. Native Code. Riesig Overhead (im Vergleich zu den anderen Vorgängen).

Außerdem spart Ihr Chef nichts.
Der erste Aufruf von LoggerFactor.getLogger erstellt den Logger und legt ihn in einer globalen name-to-Logger HashMap ab. Dies geschieht auch für den isXxxEnabled Aufrufen, denn dazu müssen Sie zuerst das Logger-Objekt erstellen...
Das Klassenobjekt wird einen zusätzlichen Zeiger für die statische Variable enthalten. Dies wird durch den Overhead ausgeglichen, der durch die Übergabe der clazz Parameter - eine zusätzliche Anweisung und ein zusätzlicher Verweis in Zeigergröße im Bytecode, so dass Sie bereits mindestens ein Byte an Klassengröße verlieren.

Der Code durchläuft außerdem eine zusätzliche Umleitung, LoggerFactory.getLogger(Class) verwendet Class#getName und delegiert an LoggerFactory.getLogger(String) .

Wenn Ihr Chef nicht auf Leistung aus ist, sondern auf die Möglichkeit, die statische Deklaration einfach zu kopieren, kann er eine Funktion verwenden, die den Aufrufstapel inspiziert und den Klassennamen abruft. Die Funktion sollte wie folgt beschriftet sein @CallerSensitive und es ist immer noch etwas, das getestet werden muss, wenn eine neue JVM verwendet wird - nicht schön, wenn man keine Kontrolle über die JVM hat, auf der der Benutzer den Code ausführt.

Der unproblematischste Ansatz wäre eine IDE, die die Instanziierung des Loggers überprüft. Das bedeutet wahrscheinlich, ein Plugin zu finden oder zu schreiben.