slf4j有一个common logger没有的功能,字符串中的{}会被替换,如下:
logger.info("Hello {}","world"); log.debug("debug......"); log.info("info......"); log.error("error......");
这个功能看起来好像很厉害。那实质上slf4j的工程师到底做了什么?会比我们单纯的字符串拼接更快吗?
在slf4j-api:1.7.21这个版本的slf4j的jar中,找到MessageFormatter类,里面有一段代码。
final public static FormattingTuple arrayFormat(final String messagePattern, final Object[] argArray, Throwable throwable) { if (messagePattern == null) { return new FormattingTuple(null, argArray, throwable); } if (argArray == null) { return new FormattingTuple(messagePattern); } int i = 0; int j; // use string builder for better multicore performance StringBuilder sbuf = new StringBuilder(messagePattern.length() + 50); int L; for (L = 0; L < argArray.length; L++) { 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, throwable); } else { // add the tail string which contains no variables and return // the result. sbuf.append(messagePattern, i, messagePattern.length()); return new FormattingTuple(sbuf.toString(), argArray, throwable); } } else { if (isEscapedDelimeter(messagePattern, j)) { if (!isDoubleEscaped(messagePattern, j)) { L--; // DELIM_START was escaped, thus should not be incremented sbuf.append(messagePattern, 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, i, j - 1); deeplyAppendParameter(sbuf, argArray[L], new HashMap<Object[], Object>()); i = j + 2; } } else { // normal case sbuf.append(messagePattern, i, j); deeplyAppendParameter(sbuf, argArray[L], new HashMap<Object[], Object>()); i = j + 2; } } } // append the characters following the last {} pair. sbuf.append(messagePattern, i, messagePattern.length()); return new FormattingTuple(sbuf.toString(), argArray, throwable); }
在这个方法中slf4j对{}进行了解析,实质也不是很高效的方法,使用indexOf找到”{}”,再对这个位置处理。简化了以后就是如下这段代码:
final public static FormattingTuple arrayFormat(final String messagePattern, final Object[] argArray, Throwable throwable) { int i = 0; int j; StringBuilder sbuf = new StringBuilder(messagePattern.length() + 50); int L; for (L = 0; L < argArray.length; L++) { j = messagePattern.indexOf("{}", i); if (j != -1){ sbuf.append(messagePattern,i,j); sbuf.append(argArray[L]); i = j+2; }else{ break; } } sbuf.append(messagePattern, i, messagePattern.length()); return new FormattingTuple(sbuf.toString(), argArray, throwable); }
而String的indexOf这个方法还是比较消耗性能的。用slf4j这个特性实质上是比我们单纯用logger.info(“Hello “+name);这个方式慢的。于是我做了下实验。用字符串拼接的方式以及StringBuilder的方式去和slf4j的{}进行比较
public String loggerFormat(){ long beginTs = System.currentTimeMillis(); logger.info("loggerFormat begin:"+String.valueOf(beginTs)); for (int i = 0; i < 1000; i++) { String[] args = new String[]{ getString(), getString(), getString(), getString(), getString() }; logger.info("测试{},{},{},{},{}",args); } String elapsedTime = "loggerFormat finish:takes "+String.valueOf(System.currentTimeMillis()-beginTs); logger.info(elapsedTime); return elapsedTime; } public String loggerString(){ long beginTs = System.currentTimeMillis(); logger.info("loggerString begin:"+String.valueOf(beginTs)); for (int i = 0; i < 1000; i++) { String info = "测试"+getString()+","+getString()+","+getString()+","+getString()+","+getString(); logger.info(info); } String elapsedTime = "loggerString finish:takes "+String.valueOf(System.currentTimeMillis()-beginTs); logger.info(elapsedTime); return elapsedTime; } public String loggerStringBulider(){ long beginTs = System.currentTimeMillis(); logger.info("loggerStringBulider begin:"+String.valueOf(beginTs)); for (int i = 0; i < 1000; i++) { StringBuilder info = new StringBuilder(); info.append("测试") .append(getString()).append(",") .append(getString()).append(",") .append(getString()).append(",") .append(getString()).append(",") .append(getString()); logger.info(info.toString()); } String elapsedTime = "loggerStringBulider finish:takes "+String.valueOf(System.currentTimeMillis()-beginTs); logger.info(elapsedTime); return elapsedTime; } public String getString(){ return UUID.randomUUID().toString(); }
得到的结果
2021-01-04 11:42:49.560 [172.27.35.1] [main] INFO c.banger.ubip.authdata.common.LoggerTest - loggerFormat finish:takes 97 2021-01-04 11:42:49.560 [172.27.35.1] [main] INFO c.banger.ubip.authdata.common.LoggerTest - loggerStringBulider finish:takes 66 2021-01-04 11:42:49.560 [172.27.35.1] [main] INFO c.banger.ubip.authdata.common.LoggerTest - loggerString finish:takes 74
最快的是StringBuilder的方式,字符串拼接的方式也比slf4j快。但是,如果是非常多变量的字符串拼接是不可取的,会产生非常多的对象,这时候可以用StringBuilder或者说用slf4j的{}的方式,注意StringBuilder的初始化长度。