what? e.getMessage()居然为null?

what? e.getMessage()居然为null?

最近在项目开发中遇到一个问题: 业务异常的时候记录日志log.error("异常:{}", e.getMessage()), 结果日志打印出来显示居然为null? 这到底是怎么回事呢? 大体研究了一下, 整理一下过程如下:

Throwable

e.getMessage()方法来自于顶级父类Throwable, 让我们先来看一下

public String getMessage() {
    return detailMessage;
}

该方法直接返回的是成员变量detailMessage, 而detailMessage则是通过构造函数传入的, 如下面的这个构造函数

public Throwable(String message) {
    fillInStackTrace();
    detailMessage = message;
}

大名鼎鼎的NullPointException

NullPointException有两个构造器, 一个传了message, 一个没传

public NullPointerException() {
    super();
}

public NullPointerException(String s) {
    super(s);
}

我们平时遇到最多的空指针是啥情况呢?

写一个最简单的例子

public static void main(String[] args) {
    Order order = null;
    System.out.println(order.getId());
}

在NullPointException类构造器加断点, 好吧, 确实是进了无参的构造器

正确的打印日志的方法

当我们使用log.error("e:{}", e.getMessage())这样的语句来打印日志的情况下, 好多根本捕获不到信息, 怎么办呢?

看一下org.slf4j.Logger, 我们平时用到的Slf4j记录日志的这个类(用lombok的@Slf4j注解也是这个类)

/**
     * Log an exception (throwable) at the ERROR level with an
     * accompanying message.
     *
     * @param msg the message accompanying the exception
     * @param t   the exception (throwable) to log
     */
public void error(String msg, Throwable t);

你会发现, 有的能直接接收异常实例当参数唉? 注释上写着the exception to log(要记录的异常), 那他内部怎么实现的呢? 直接传整个实例能打印出日志吗?

找一个Logback的实现类ch.qos.logback.classic.Logger看一下, 一层层的点方法, 最终到了这

SyslogOutputStream sos;
.....
@Override
protected void append(E eventObject) {
    if (!isStarted()) {
        return;
    }

    try {
        // 这里doLayout方法用于展示不同的形式, 输出的是Event对象
        String msg = layout.doLayout(eventObject);
        if (msg == null) {
            return;
        }
        if (msg.length() > maxMessageSize) {
            msg = msg.substring(0, maxMessageSize);
        }
        sos.write(msg.getBytes(charset));
        sos.flush();
        postProcess(eventObject, sos);
    } catch (IOException ioe) {
        addError("Failed to send diagram to " + syslogHost, ioe);
    }
}

最终把Event输出了, 这个Event就是对日志记录参数的封装, 我们再看看Event是怎么构造的

public LoggingEvent(String fqcn, Logger logger, Level level, String message, Throwable throwable, Object[] argArray) {
    this.fqnOfLoggerClass = fqcn;
    this.loggerName = logger.getName();
    this.loggerContext = logger.getLoggerContext();
    this.loggerContextVO = loggerContext.getLoggerContextRemoteView();
    this.level = level;

    this.message = message;
    this.argumentArray = argArray;

    if (throwable == null) {
        throwable = extractThrowableAnRearrangeArguments(argArray);
    }

    // 把Throwble放入一个Throwable的代理对象中
    if (throwable != null) {
        this.throwableProxy = new ThrowableProxy(throwable);
        LoggerContext lc = logger.getLoggerContext();
        if (lc.isPackagingDataEnabled()) {
            this.throwableProxy.calculatePackagingData();
        }
    }

    timeStamp = System.currentTimeMillis();
}

试一试吧

我只能说好使了, 图就不贴了

拓展

上面举例的那个方法public void error(String msg, Throwable t);, 第一个参数是异常的信息, 第二个参数是异常实例; 但是我们用Slf4j最舒服的地方不就是那个{}占位符吗? 现在又要拼字符串了?

另一个方法

public void error(String format, Object... args) {
    this.logMessageWithFormat("ERROR", format, args);
}

Logback中的实现和上面的流程基本一致, 其他的实现暂且不论…

好了好了, 这下舒服了 !!!

总结

综上所述, 正确的记录错误异常日志的方法

log.error("e:{}", e.getMessage(), e)