背景:
在业务代码中，发生异常，我们常常习惯把上下文和异常堆栈打印下来，方便排查问题，而 org.slf4j.Logger 接口中常用的方法如下:
以info为例:
/**
* Log a message at the INFO level.
*
* @param msg the message string to be logged
*/
public void info(String msg);
/**
* Log a message at the INFO level according to the specified format
* and argument.
* <p/>
* <p>This form avoids superfluous object creation when the logger
* is disabled for the INFO level. </p>
*
* @param format the format string
* @param arg the argument
*/
public void info(String format, Object arg);
/**
* Log a message at the INFO level according to the specified format
* and arguments.
* <p/>
* <p>This form avoids superfluous object creation when the logger
* is disabled for the INFO level. </p>
*
* @param format the format string
* @param arg1 the first argument
* @param arg2 the second argument
*/
public void info(String format, Object arg1, Object arg2);
/**
* Log a message at the INFO level according to the specified format
* and arguments.
* <p/>
* <p>This form avoids superfluous string concatenation when the logger
* is disabled for the INFO level. However, this variant incurs the hidden
* (and relatively small) cost of creating an <code>Object[]</code> before invoking the method,
* even if this logger is disabled for INFO. The variants taking
* {@link #info(String, Object) one} and {@link #info(String, Object, Object) two}
* arguments exist solely in order to avoid this hidden cost.</p>
*
* @param format the format string
* @param arguments a list of 3 or more arguments
*/
public void info(String format, Object... arguments);
/**
* Log an exception (throwable) at the INFO level with an
* accompanying message.
*
* @param msg the message accompanying the exception
* @param t the exception (throwable) to log
*/
public void info(String msg, Throwable t);
而针对抛异常的接口似乎只能通过调用,
/**
- Log an exception (throwable) at the INFO level with an
- accompanying message.
- @param msg the message accompanying the exception
- @param t the exception (throwable) to log
*/
public void info(String msg, Throwable t);
但是如果这么处理我们就没法打印上下文，如果这么写
log.info("xxx:{},xxxx:{},异常:{}",x1,x2,throwable)
能解决打印堆栈的问题吗？
其实不能，那么我们如何处理，难道需要我们先自己把上下文处理好，调用
log.info(msg,throwable) 才能打印吗？
这么做当然能解决，但是 对以前日志的改造工作量大，那么如何处理呢？
正确的姿势:
log.info("xxx:{},xxx:{},异常:",x1,x2,throwable)
说明:
- 异常是最后一个参数
- 占位符的个数比实际参数要少
划重点:
throwable 没有站位符即可，为什么？？？
我们来分析下源码
因为我们是使用logback写的日志：
我们以如下代码做例子:
try {
int i = 0;
int j= 5;
int r = j / i;
}catch (Exception e){
log.info("除数:{},被除数:{},异常:",j,i,e);
}
会走到
Logger
ch.qos.logback.classic.Logger下面的
// 此时 argArray 代表的是 【j,i,e】
// format 代表的是 除数:{},被除数:{},异常:
public void info(String format, Object[] argArray) {
filterAndLog_0_Or3Plus(FQCN, null, Level.INFO, format, argArray, null);
}
private void filterAndLog_0_Or3Plus(final String localFQCN,
final Marker marker, final Level level, final String msg,
final Object[] params, final Throwable t) {
final FilterReply decision = loggerContext
.getTurboFilterChainDecision_0_3OrMore(marker, this, level, msg,
params, t);
if (decision == FilterReply.NEUTRAL) {
if (effectiveLevelInt > level.levelInt) {
return;
}
} else if (decision == FilterReply.DENY) {
return;
}
// 此处替换占位符处理异常
buildLoggingEventAndAppend(localFQCN, marker, level, msg, params, t);
}
private void buildLoggingEventAndAppend(final String localFQCN,
final Marker marker, final Level level, final String msg,
final Object[] params, final Throwable t) {
// 此处处理的占位符和异常
LoggingEvent le = new LoggingEvent(localFQCN, this, level, msg, t, params);
le.setMarker(marker);
callAppenders(le);
}
LoggingEvent
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;
// 此处处理占位符和异常
FormattingTuple ft = MessageFormatter.arrayFormat(message, argArray);
// 此处得到的 ft 中，formattedMessage = 除数:5,被除数:0,异常:
formattedMessage = ft.getMessage();
// 入参中 throwable 是空，因此会走到此处
if (throwable == null) {
// 排除最后一个异常的参数数组
argumentArray = ft.getArgArray();
// 从 FormattingTuple 中得到 异常，也就是 最后一个的异常参数
throwable = ft.getThrowable();
} else {
this.argumentArray = argArray;
}
// 真正打印异常日志的在此处
if (throwable != null) {
// ThrowableProxy 会提取异常的堆栈日志:
this.throwableProxy = new ThrowableProxy(throwable);
LoggerContext lc = logger.getLoggerContext();
if (lc.isPackagingDataEnabled()) {
this.throwableProxy.calculatePackagingData();
}
}
timeStamp = System.currentTimeMillis();
}
FormattingTuple
final public static FormattingTuple arrayFormat(final String messagePattern,
final Object[] argArray) {
// 提取异常，逻辑：判断参数的最后一个是否是异常
Throwable throwableCandidate = getThrowableCandidate(argArray);
if (messagePattern == null) {
return new FormattingTuple(null, argArray, throwableCandidate);
}
if (argArray == null) {
return new FormattingTuple(messagePattern);
}
int i = 0;
int j;
StringBuffer sbuf = new StringBuffer(messagePattern.length() + 50);
int L;
// 遍历参数
for (L = 0; L < argArray.length; L++) {
// static final String DELIM_STR = "{}";
// 查找占位符 DELIM_STR 也就是 {}
j = messagePattern.indexOf(DELIM_STR, i);
// 当 参数比占位符 多的时候，会走到此处
if (j == -1) {
// no more variables
if (i == 0) { // this is a simple string
return new FormattingTuple(messagePattern, argArray,
throwableCandidate);
} else { // add the tail string which contains no variables and return
// the result.
sbuf.append(messagePattern.substring(i, messagePattern.length()));
// 再次走到此处，此时，sbuf = 除数:5,被除数:0,异常:，
// argArray 没变， throwableCandidate 是 我们上面提取出来的异常
return new FormattingTuple(sbuf.toString(), argArray,
throwableCandidate);
}
} else {
if (isEscapedDelimeter(messagePattern, j)) {
if (!isDoubleEscaped(messagePattern, j)) {
L--; // DELIM_START was escaped, thus should not be incremented
sbuf.append(messagePattern.substring(i, j - 1));
sbuf.append(DELIM_START);
i = j + 1;
} else {
// The escape character preceding the delimiter start is
// itself escaped: "abc x:\\{}"
// we have to consume one backward slash
sbuf.append(messagePattern.substring(i, j - 1));
deeplyAppendParameter(sbuf, argArray[L], new HashMap());
i = j + 2;
}
} else {
// normal case
// 找到占位符，并用对应的参数进行替换，并修改 i 为 大于 0的值
sbuf.append(messagePattern.substring(i, j));
deeplyAppendParameter(sbuf, argArray[L], new HashMap());
i = j + 2;
}
}
}
// append the characters following the last {} pair.
sbuf.append(messagePattern.substring(i, messagePattern.length()));
if (L < argArray.length - 1) {
return new FormattingTuple(sbuf.toString(), argArray, throwableCandidate);
} else {
return new FormattingTuple(sbuf.toString(), argArray, null);
}
}
static final Throwable getThrowableCandidate(Object[] argArray) {
if (argArray == null || argArray.length == 0) {
return null;
}
final Object lastEntry = argArray[argArray.length - 1];
if (lastEntry instanceof Throwable) {
return (Throwable) lastEntry;
}
return null;
}
private static void deeplyAppendParameter(StringBuffer sbuf, Object o,
Map seenMap) {
if (o == null) {
sbuf.append("null");
return;
}
// 因为是String类型，此处添加
if (!o.getClass().isArray()) {
safeObjectAppend(sbuf, o);
} else {
// check for primitive array types because they
// unfortunately cannot be cast to Object[]
if (o instanceof boolean[]) {
booleanArrayAppend(sbuf, (boolean[]) o);
} else if (o instanceof byte[]) {
byteArrayAppend(sbuf, (byte[]) o);
} else if (o instanceof char[]) {
charArrayAppend(sbuf, (char[]) o);
} else if (o instanceof short[]) {
shortArrayAppend(sbuf, (short[]) o);
} else if (o instanceof int[]) {
intArrayAppend(sbuf, (int[]) o);
} else if (o instanceof long[]) {
longArrayAppend(sbuf, (long[]) o);
} else if (o instanceof float[]) {
floatArrayAppend(sbuf, (float[]) o);
} else if (o instanceof double[]) {
doubleArrayAppend(sbuf, (double[]) o);
} else {
objectArrayAppend(sbuf, (Object[]) o, seenMap);
}
}
}
private static void safeObjectAppend(StringBuffer sbuf, Object o) {
try {
String oAsString = o.toString();
sbuf.append(oAsString);
} catch (Throwable t) {
System.err
.println("SLF4J: Failed toString() invocation on an object of type ["
+ o.getClass().getName() + "]");
t.printStackTrace();
sbuf.append("[FAILED toString()]");
}
}
走到了
// 再次走到此处，此时，sbuf = 除数:5,被除数:0,异常:，
// argArray 没变， throwableCandidate 是 我们上面提取出来的异常
public FormattingTuple(String message, Object[] argArray, Throwable throwable) {
this.message = message;
this.throwable = throwable;
if(throwable == null) {
this.argArray = argArray;
} else {
// 拷贝参数去掉最后一个参数(也就是异常参数)， 此时会回到 LoggingEvent 方法中继续执行
this.argArray = trimmedCopy(argArray);
}
}
static Object[] trimmedCopy(Object[] argArray) {
if(argArray == null || argArray.length == 0) {
throw new IllegalStateException("non-sensical empty or null argument array");
}
final int trimemdLen = argArray.length -1;
Object[] trimmed = new Object[trimemdLen];
System.arraycopy(argArray, 0, trimmed, 0, trimemdLen);
return trimmed;
}
ThrowableProxy
public ThrowableProxy(Throwable throwable) {
this.throwable = throwable;
this.className = throwable.getClass().getName();
this.message = throwable.getMessage();
// 此处得到的堆栈的相关信息，因此后续打印中就包含了异常堆栈信息
this.stackTraceElementProxyArray =
ThrowableProxyUtil.steArrayToStepArray(throwable
.getStackTrace());
Throwable nested = throwable.getCause();
if (nested != null) {
this.cause = new ThrowableProxy(nested);
this.cause.commonFrames = ThrowableProxyUtil
.findNumberOfCommonFrames(nested.getStackTrace(),
stackTraceElementProxyArray);
}
if(GET_SUPPRESSED_METHOD != null) {
// this will only execute on Java 7
try {
Object obj = GET_SUPPRESSED_METHOD.invoke(throwable);
if(obj instanceof Throwable[]) {
Throwable[] throwableSuppressed = (Throwable[]) obj;
if(throwableSuppressed.length > 0) {
suppressed = new ThrowableProxy[throwableSuppressed.length];
for(int i=0;i<throwableSuppressed.length;i++) {
this.suppressed[i] = new ThrowableProxy(throwableSuppressed[i]);
this.suppressed[i].commonFrames = ThrowableProxyUtil
.findNumberOfCommonFrames(throwableSuppressed[i].getStackTrace(),
stackTraceElementProxyArray);
}
}
}
} catch (IllegalAccessException e) {
// ignore
} catch (InvocationTargetException e) {
// ignore
}
}
}
2384
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
