日志是我们日常开发经常用到的,日志是为了方便排查问题。
然而有在有些API的日志却用法容易混淆,出现一些意想不到的异常。
比如在定时任务 XxlJobLogger.log() 和 slf4j 日志框架提供的 log.info()。
我们使用的最多的就是 slf4j 框架提供的 Logger.info(); 使用非常方便,只需要在所在类前面加上注解 @Slf4j,就可以直接使用 log.info() 方法。
log.info() 是以 INFO 级别进行日志打印,它有以下四个重载方法:
//只打印一个字符串
public void info(String msg);
//按照指定的格式打印,内容是1个参数(每个参数在format中使用一个占位符{})
public void info(String format, Object arg);
//按照指定的格式打印,内容是2个参数(每个参数在format中使用一个占位符{})
public void info(String format, Object arg1, Object arg2);
//按照指定的格式打印,内容是多个参数(每个参数在format中使用一个占位符{})
public void info(String format, Object... arguments);
//以 INFO 级别打印一个异常 public void info(String msg, Throwable t);
使用如下:
log.info("log a String: LogInfo");
log.info("log a String: {}", "Single String");
log.info("log two String: {}, {}", "First", "Second");
log.info("log multi String: {}, {}, {}", "First", "Second", "Third");
log.info("log an exception: {}", IndexOutOfBoundsException.class);
输出结果:
log a String: LogInfo
log a String: Single String
log two String: First, Second
log multi String: First, Second, Third
log an exception: class java.lang.IndexOutOfBoundsException
然而在 XXLjob 中的 log() 方法,使用占位符{} 则会发生异常。
反例:
XxlJobLogger.log("Task id:【" + task.getId() + "】执行完毕,处理结果:{}", message);
结果是抛出异常:
大致原因是在 XxlJob.log() 方法的源码中,并不会将占位符 {} 替换为 message ,而是将 {} 括号里面的字符转成 Integer 类型再拼接,也就是{}里面只能使用整数。
所以以上反例中括号{}里得到的是一个空字符串“”,在字符串转 Integer 时发生了异常(同理,在{}里面传入字符也会抛出异常)
private void makeFormat(int position, int offsetNumber,
StringBuilder[] textSegments)
{
String[] segments = new String[textSegments.length];
for (int i = 0; i < textSegments.length; i++) {
StringBuilder oneseg = textSegments[i];
segments[i] = (oneseg != null) ? oneseg.toString() : "";
}
// get the argument number
int argumentNumber;
try {
//SEG_INDEX为1
//segments[]={"Task id:【21】上传完毕,处理结果:",""}
//此时segments[1]="",转Integer发生异常
argumentNumber = Integer.parseInt(segments[SEG_INDEX]); // always unlocalized!
} catch (NumberFormatException e) {
throw new IllegalArgumentException("can't parse argument number: "
+ segments[SEG_INDEX], e);
}
if (argumentNumber < 0) {
throw new IllegalArgumentException("negative argument number: "
+ argumentNumber);
}
// resize format information arrays if necessary
if (offsetNumber >= formats.length) {
int newLength = formats.length * 2;
Format[] newFormats = new Format[newLength];
int[] newOffsets = new int[newLength];
int[] newArgumentNumbers = new int[newLength];
System.arraycopy(formats, 0, newFormats, 0, maxOffset + 1);
System.arraycopy(offsets, 0, newOffsets, 0, maxOffset + 1);
System.arraycopy(argumentNumbers, 0, newArgumentNumbers, 0, maxOffset + 1);
formats = newFormats;
offsets = newOffsets;
argumentNumbers = newArgumentNumbers;
}
int oldMaxOffset = maxOffset;
maxOffset = offsetNumber;
offsets[offsetNumber] = segments[SEG_RAW].length();
argumentNumbers[offsetNumber] = argumentNumber;
// now get the format
Format newFormat = null;
if (segments[SEG_TYPE].length() != 0) {
int type = findKeyword(segments[SEG_TYPE], TYPE_KEYWORDS);
switch (type) {
case TYPE_NULL:
// Type "" is allowed. e.g., "{0,}", "{0,,}", and "{0,,#}"
// are treated as "{0}".
break;
case TYPE_NUMBER:
switch (findKeyword(segments[SEG_MODIFIER], NUMBER_MODIFIER_KEYWORDS)) {
case MODIFIER_DEFAULT:
newFormat = NumberFormat.getInstance(locale);
break;
case MODIFIER_CURRENCY:
newFormat = NumberFormat.getCurrencyInstance(locale);
break;
case MODIFIER_PERCENT:
newFormat = NumberFormat.getPercentInstance(locale);
break;
case MODIFIER_INTEGER:
newFormat = NumberFormat.getIntegerInstance(locale);
break;
default: // DecimalFormat pattern
try {
newFormat = new DecimalFormat(segments[SEG_MODIFIER],
DecimalFormatSymbols.getInstance(locale));
} catch (IllegalArgumentException e) {
maxOffset = oldMaxOffset;
throw e;
}
break;
}
break;
case TYPE_DATE:
case TYPE_TIME:
int mod = findKeyword(segments[SEG_MODIFIER], DATE_TIME_MODIFIER_KEYWORDS);
if (mod >= 0 && mod < DATE_TIME_MODIFIER_KEYWORDS.length) {
if (type == TYPE_DATE) {
newFormat = DateFormat.getDateInstance(DATE_TIME_MODIFIERS[mod],
locale);
} else {
newFormat = DateFormat.getTimeInstance(DATE_TIME_MODIFIERS[mod],
locale);
}
} else {
// SimpleDateFormat pattern
try {
newFormat = new SimpleDateFormat(segments[SEG_MODIFIER], locale);
} catch (IllegalArgumentException e) {
maxOffset = oldMaxOffset;
throw e;
}
}
break;
case TYPE_CHOICE:
try {
// ChoiceFormat pattern
newFormat = new ChoiceFormat(segments[SEG_MODIFIER]);
} catch (Exception e) {
maxOffset = oldMaxOffset;
throw new IllegalArgumentException("Choice Pattern incorrect: "
+ segments[SEG_MODIFIER], e);
}
break;
default:
maxOffset = oldMaxOffset;
throw new IllegalArgumentException("unknown format type: " +
segments[SEG_TYPE]);
}
}
formats[offsetNumber] = newFormat;
}
正例:应该直接使用 + 拼接成一个字符串,作为入参,
XxlJobLogger.log("Task id:【" + task.getId() + "】上传完毕,处理结果:" + message);
输出结果:
Task id:【24】执行完毕,处理结果:readURL ERROR
如果在 {} 中传入一个数字,
XxlJobLogger.log("Task id:【" + task.getId() + "】执行完毕,处理结果:{1}", message);
输出结果:
Task id:【24】执行完毕,处理结果:{1}
有意思的是,message 并不能被打印出来