XxlJobLogger日志输出的坑

1,584 阅读57分钟

日志是我们日常开发经常用到的,日志是为了方便排查问题。

然而有在有些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 并不能被打印出来