slf4j、logback、log4j打印出的日志行号不正确，如何获取正确的行号（调用者类里的行号）

目录

环境信息

说明

配置信息

问题描述

原因分析

解决方案

解决思路

LocationAwareLogger.java

ch.qos.logback.classic.Logger.java

解决方法

Log.java

环境信息

SpringBoot 2.1.15.RELEASE

slf4j:1.7.25

logback:1.2.3

说明

        系统使用的是slf4j+logback日志组合，而且为了系统的个性化需求，封装了自己的日志操作类Log.java，不是直接使用slf4j的API：

private static Logger logger = LoggerFactory.getLogger(xxx.class);

配置信息

 logback配置：

logback.xml

<?xml version="1.0" encoding="UTF-8"?>
<configuration><property resource="configs-xml-logback.properties" /><appender name="stdout" class="ch.qos.logback.core.ConsoleAppender"><layout class="ch.qos.logback.classic.PatternLayout"><pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level %msg 【%t】【%logger{0}:%L】%n</pattern></layout></appender><appender name="bizLog"class="ch.qos.logback.core.rolling.RollingFileAppender"><file>${log.root.path}/${app.name}/${app.name}.log</file><rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy"><fileNamePattern>${log.root.path}/${app.name}/${app.name}.%d{yyyy-MM-dd}.log</fileNamePattern><maxHistory>3</maxHistory></rollingPolicy><encoder><pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level %msg 【%t】【%logger{0}:%L】%n</pattern></encoder></appender><!-- 异步输出 --><appender name="ASYNC" class="ch.qos.logback.classic.AsyncAppender"><!-- 不丢失日志.默认的,如果队列的80%已满,则会丢弃TRACT、DEBUG、INFO级别的日志 --><discardingThreshold>0</discardingThreshold><!-- 更改默认的队列的深度,该值会影响性能.默认值为256 --><queueSize>256</queueSize><!-- 添加附加的appender,最多只能添加一个 --><appender-ref ref="bizLog" /></appender><logger name="java.sql.Connection" level="${sql.log.level}" /><logger name="java.sql.Statement" level="${sql.log.level}" /><logger name="java.sql.PreparedStatement" level="${sql.log.level}" /><logger name="com.eternalinfo" level="${log.dev.level}" /><root level="${log.level}"><appender-ref ref="stdout" /><appender-ref ref="ASYNC" /></root><jmxConfigurator />
</configuration>  

configs-xml-logback.properties

app.name=myApp
log.root.path=/home/myApp-logs
log.level=INFO
log.dev.level=DEBUG
sql.log.level=INFO

问题描述

logback的配置是生效的，%L是打印行号，在日志里也能显示出行号出来。

问题在于有很多行号的值不对，而且都是些重复的行数，比如51、117、149。

2021-09-22 14:06:49.238 INFO  加载第7个子配置文件:file [D:\xxx.xml] 【main】【ResourceLookuper:117】
2021-09-22 14:06:49.248 INFO  加载第8个子配置文件:file [D:\yyy.xml] 【main】【ResourceLookuper:117】
2021-09-22 14:06:49.256 DEBUG 总共加载了9配置文件 【main】【ResourceLookuper:51】
2021-09-22 14:06:49.256 DEBUG 开始处理已加载的第0个子配置文件:xxx.xml 【main】【XmlConfigDeserializer:51】
2021-09-22 14:38:27.517 WARN  获取不到HttpServletRequest对象 【pool-14-thread-1】【HttpHolderUtil:149】

原因分析

        问题出现以后，最开始是猜想这些行号是代理类里的行号，不过很快排除了：有些类并没有使用代理，打印出的日志行号还是不对。

        仔细看了下日志的行号，发现了一个规律：

DEBUG级别的日志的行号是51

INFO级别的日志的行号是117

WARN级别的日志的行号是149

所以问题很可能出在日志操作类Log.java上，这些行号是日志操作类Log里的行号。打开Log类看了下，发现确实是这样：

Log.java  有省略代码

import org.slf4j.Logger;import ch.qos.logback.classic.LoggerContext;public class Log
{public static final String LOG_LEVEL_KEY="log.level";public static final String OUT_LOG_CLASS_REGEX_KEY="out.log.class.regex";private Logger logger;private static final String PLACE_HODER_STR="\\{\\}";Log(Class<?> clz,LoggerContext loggerContext){
//		logger=LoggerFactory.getLogger(clz); 
//		if(this.loggerContext==null) {
//			loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory();
//		}logger=loggerContext.getLogger(clz);}private Logger getCurrentLog(){return logger;}private String getLogId(Object message) {String logId = LogIdUtil.getLogId()==null ?"":LogIdUtil.getLogId()+"||";return logId+message;}/*** debug记录* @param message* @param e*/public void debug(Object message,Throwable e){message = getLogId(message);getCurrentLog().debug(((String)message).replace("{}", ""),e);}/*** message记录* @param message* @param e*/public void info(Object message,Throwable e){message = getLogId(message);getCurrentLog().info(((String)message).replace("{}", ""),e);}public void warn(Object message,Throwable e){message = getLogId(message);getCurrentLog().warn(((String)message).replace("{}", ""),e);}...}

原因在于打印日志是使用的日志操作类Log，真正调用slf4j的debug、info、warn的地方是Log类，所以打印出的行号是Log类里的行号，而不是调用Log类的地方（以下称为调用者类）的行号

getCurrentLog().debug(((String)message).replace("{}", ""),e);

解决方案

解决思路

        在使用slf4j的时候，默认引用的是slf4j的org.slf4j.Logger接口（实现类看真正的日志框架是什么，比如这里是logback的ch.qos.logback.classic.Logger），而这个Logger接口还有一个子接口org.slf4j.spi.LocationAwareLogger，logback的ch.qos.logback.classic.Logger实现类也实现了这个接口：

LocationAwareLogger.java

package org.slf4j.spi;import org.slf4j.Logger;
import org.slf4j.Marker;/*** An <b>optional</b> interface helping integration with logging systems capable of * extracting location information. This interface is mainly used by SLF4J bridges * such as jcl-over-slf4j, jul-to-slf4j and log4j-over-slf4j or {@link Logger} wrappers* which need to provide hints so that the underlying logging system can extract* the correct location information (method name, line number).** @author Ceki Gulcu* @since 1.3*/
public interface LocationAwareLogger extends Logger {// these constants should be in EventContants. However, in order to preserve binary backward compatibility// we keep these constants herefinal public int TRACE_INT = 00;final public int DEBUG_INT = 10;final public int INFO_INT = 20;final public int WARN_INT = 30;final public int ERROR_INT = 40;/*** Printing method with support for location information. * * @param marker The marker to be used for this event, may be null.* @param fqcn The fully qualified class name of the <b>logger instance</b>,* typically the logger class, logger bridge or a logger wrapper.* @param level One of the level integers defined in this interface* @param message The message for the log event* @param t Throwable associated with the log event, may be null.*/public void log(Marker marker, String fqcn, int level, String message, Object[] argArray, Throwable t);}

ch.qos.logback.classic.Logger.java

public final class Logger implements org.slf4j.Logger, LocationAwareLogger, AppenderAttachable<ILoggingEvent>, Serializable {private static final long serialVersionUID = 5454405123156820674L; // 8745934908040027998L;/*** The fully qualified name of this class. Used in gathering caller* information.*/public static final String FQCN = ch.qos.logback.classic.Logger.class.getName();public void log(Marker marker, String fqcn, int levelInt, String message, Object[] argArray, Throwable t) {Level level = Level.fromLocationAwareLoggerInteger(levelInt);filterAndLog_0_Or3Plus(fqcn, marker, level, message, argArray, t);}
...
}

LocationAwareLogger这个接口的说明里写了：

这个可选接口可以帮助日志系统来输出正确的引用位置信息（方法名、行号），可以用于slf4j的桥连，比如jcl-over-slf4j, jul-to-slf4j and log4j-over-slf4j or Logger wrappers （或者Logger的装饰模式）

在这里，日志操作类Log相当于Logger的装饰器。

解决方法

修改日志操作类Log里的debug、info、warn等方法，改成LocationAwareLogger里的log方法

可以参考jcl-over-slf4j包里的org.apache.commons.logging.impl.SLF4JLocationAwareLog

Log.java

import org.slf4j.Logger;import ch.qos.logback.classic.LoggerContext;public class Log
{public static final String LOG_LEVEL_KEY="log.level";public static final String OUT_LOG_CLASS_REGEX_KEY="out.log.class.regex";private Logger logger;private static final String PLACE_HODER_STR="\\{\\}";Log(Class<?> clz,LoggerContext loggerContext){
//		logger=LoggerFactory.getLogger(clz); 
//		if(this.loggerContext==null) {
//			loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory();
//		}logger=loggerContext.getLogger(clz);}private Logger getCurrentLog(){return logger;}private String getLogId(Object message) {String logId = LogIdUtil.getLogId()==null ?"":LogIdUtil.getLogId()+"||";return logId+message;}/*** debug记录* @param message* @param e*/public void debug(Object message, Throwable e) {message = getLogId(message);// 做判断是以防更改了日志实现框架之后，logger未实现LocationAwareLogger接口。如果只是logback使用，不需要if (this.logger instanceof LocationAwareLogger) {((LocationAwareLogger) this.logger).log(null, FQCN, LocationAwareLogger.DEBUG_INT, (String) message, null, e);return;}this.logger.debug(((String) message).replace("{}", ""), e);}/*** message记录* @param message* @param e*/public void info(Object message, Throwable e) {message = getLogId(message);if (this.logger instanceof LocationAwareLogger) {((LocationAwareLogger) this.logger).log(null, FQCN, LocationAwareLogger.INFO_INT, (String) message, null, e);return;}getCurrentLog().info(((String) message).replace("{}", ""), e);}public void warn(Object message, Throwable e) {message = getLogId(message);if (this.logger instanceof LocationAwareLogger) {((LocationAwareLogger) this.logger).log(null, FQCN, LocationAwareLogger.WARN_INT, (String) message, null, e);return;}getCurrentLog().warn(((String) message).replace("{}", ""), e);}...}

参考：

Slf4j+logback实现日志打印-获取调用者类及方法行数信息_wang37444的专栏