目录
ch.qos.logback.classic.Logger.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 here
final 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的专栏