系统框架
Springboot + DUbbo + Mybatis-plus
日志框架为:log4j2.x
问题描述
目前项目中都是log.info(“xxxxxxxx”)或者log.error,但是由于探针埋点的包都是特定的,所以尤其是我们在项目中的这些日志信息就无法体现在Skywalking的UI链路上,甚至异常由于我们会自己抛出相应的异常,而原始的异常堆栈信息无法打印到Skywalking里。这不是我们想的要效果,我们希望开发的过程中,只需要用traceId即可查询出所有需要看到的信息,大家才能快速的解决问题,同时,结合Skywalking提供的链路增加用法,那种代码侵入式的做法是不现实的,我们并不能大面积的去改动。
解决思路
鉴于上述问题描述的效果,以及我们面对的改动面积,所以达到效果的同时又能最小变动成为我们的目标!那就是在调用log.info方法的时候,我们能同时执行下ActiveSpan.info然后收集到Skywalking里面去。了解过Slf4j和log4j的关系以及log4j的使用后,我们有下面两种方案!
解决方案一:实现我们自己的LogApender,然后更改log4j的xml文件
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.core.Filter;
import org.apache.logging.log4j.core.Layout;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.appender.AbstractAppender;
import org.apache.logging.log4j.core.config.Property;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.config.plugins.PluginAttribute;
import org.apache.logging.log4j.core.config.plugins.PluginElement;
import org.apache.logging.log4j.core.config.plugins.PluginFactory;
import org.apache.logging.log4j.core.layout.PatternLayout;
import org.apache.skywalking.apm.toolkit.trace.ActiveSpan;
import java.io.Serializable;
/**
* @author wangguodong
*/
@Plugin(name = "SkywalkingLog", category = "Core", elementType = "appender", printObject = true)
public class LogAppender extends AbstractAppender {
protected LogAppender(String name, Filter filter, Layout<? extends Serializable> layout, boolean ignoreExceptions, Property[] properties) {
super(name, filter, layout, ignoreExceptions, properties);
}
@Override
public void append(LogEvent logEvent) {
// 这里对log信息重新调用放到链路里
if (Level.ERROR.equals(logEvent.getLevel())){
ActiveSpan.error(logEvent.getMessage().getFormattedMessage());
ActiveSpan.error(logEvent.getThrown());
} else if (Level.INFO.equals(logEvent.getLevel())) {
ActiveSpan.info(logEvent.getMessage().getFormattedMessage());
} else if (Level.DEBUG.equals(logEvent.getLevel())) {
ActiveSpan.debug(logEvent.getMessage().getFormattedMessage());
}
}
@PluginFactory
public static LogAppender createAppender(@PluginAttribute("name") String name,
@PluginElement("Filter") final Filter filter,
@PluginElement("Layout") Layout<? extends Serializable> layout,
@PluginAttribute("ignoreExceptions") boolean ignoreExceptions) {
if (name == null) {
LOGGER.error("No name provided for MyCustomAppenderImpl");
return null;
}
if (layout == null) {
layout = PatternLayout.createDefaultLayout();
}
return new LogAppender(name, filter, layout, ignoreExceptions, null);
}
}
<?xml version="1.0" encoding="UTF-8"?>
<configuration status="WARN">
<Properties>
<property name="APP_NAME">bigtree-invoice</property>
<property name="LOGGER_LEVEL">INFO</property>
<property name="LOGGER_PATH">/data/logs</property>
<Property name="LOG_HOME">${LOGGER_PATH}/${APP_NAME}</Property>
<Property name="FILE_SIZE">10M</Property>
<Property name="log_pattern">%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] [%X{traceId}] %-5level %logger{36} - %msg%n</Property>
<Property name="rolling_file_name">-%d{yyyy-MM-dd}.%i.zip</Property>
<Property name="rollover_strategy_max">30</Property>
<Property name="LOG_HOME_PROJECT">${LOG_HOME}/${APP_NAME}-project</Property>
<Property name="LOG_HOME_PROJECT_ERROR">${LOG_HOME}/${APP_NAME}-project-error</Property>
<Property name="LOG_HOME_MSDP">${LOG_HOME}/${APP_NAME}-msdp</Property>
<Property name="LOG_HOME_SQL">${LOG_HOME}/${APP_NAME}-sql</Property>
<Property name="LOG_HOME_ACCESS">${LOG_HOME}/${APP_NAME}-access</Property>
<Property name="LOG_HOME_ACCESS_ERROR">${LOG_HOME}/${APP_NAME}-access-error</Property>
</Properties>
<appenders>
<Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="${log_pattern}" />
</Console>
<RollingRandomAccessFile name="projectRolling"
fileName="${LOG_HOME_PROJECT}.log"
filePattern="${LOG_HOME_PROJECT}${rolling_file_name}"
immediateFlush="false" append="true">
<PatternLayout>
<Pattern>${log_pattern}</Pattern>
<Charset>UTF-8</Charset>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="${FILE_SIZE}"/>
</Policies>
<DefaultRolloverStrategy max="${rollover_strategy_max}" />
</RollingRandomAccessFile>
<RollingRandomAccessFile name="projectErrorRolling"
fileName="${LOG_HOME_PROJECT_ERROR}.log"
filePattern="${LOG_HOME_PROJECT_ERROR}${rolling_file_name}"
immediateFlush="false" append="true">
<Filters>
<ThresholdFilter level="${LOGGER_LEVEL}" onMatch="ACCEPT" onMismatch="DENY" />
</Filters>
<PatternLayout>
<Pattern>${log_pattern}</Pattern>
<Charset>UTF-8</Charset>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="${FILE_SIZE}"/>
</Policies>
<DefaultRolloverStrategy max="${rollover_strategy_max}" />
</RollingRandomAccessFile>
<RollingRandomAccessFile name="msdpRolling"
fileName="${LOG_HOME_MSDP}.log"
filePattern="${LOG_HOME_MSDP}${rolling_file_name}"
immediateFlush="false" append="true">
<PatternLayout>
<Pattern>${log_pattern}</Pattern>
<Charset>UTF-8</Charset>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="${FILE_SIZE}"/>
</Policies>
<DefaultRolloverStrategy max="${rollover_strategy_max}" />
</RollingRandomAccessFile>
<RollingRandomAccessFile name="sqlRolling"
fileName="${LOG_HOME_SQL}.log"
filePattern="${LOG_HOME_SQL}${rolling_file_name}"
immediateFlush="false" append="true">
<PatternLayout>
<Pattern>${log_pattern}</Pattern>
<Charset>UTF-8</Charset>
</PatternLayout>
<Policies>
<SizeBasedTriggeringPolicy size="${FILE_SIZE}"/>
</Policies>
<DefaultRolloverStrategy max="${rollover_strategy_max}" />
</RollingRandomAccessFile>
<-- 添加我们自己的apender -->
<SkywalkingLog name="SkywalkingLog">
<PatternLayout pattern="${log_pattern}" />
</SkywalkingLog>
</appenders>
<loggers>
<AsyncLogger name="org.springframework" level="${LOGGER_LEVEL}" additivity="false">
<appender-ref ref="Console"/>
<appender-ref ref="projectRolling"/>
<appender-ref ref="projectErrorRolling"/>
</AsyncLogger>
<AsyncLogger name="com.alibaba.dubbo" level="${LOGGER_LEVEL}" additivity="false">
<appender-ref ref="Console"/>
<appender-ref ref="projectRolling"/>
<appender-ref ref="projectErrorRolling"/>
</AsyncLogger>
<AsyncLogger name="druid.sql" level="${LOGGER_LEVEL}" additivity="false">
<appender-ref ref="Console"/>
<appender-ref ref="sqlRolling"/>
</AsyncLogger>
<AsyncLogger name="org.mybatis" level="${LOGGER_LEVEL}" additivity="false">
<appender-ref ref="Console"/>
<appender-ref ref="sqlRolling"/>
</AsyncLogger>
<AsyncLogger name="com.jeedev.msdp" level="${LOGGER_LEVEL}" additivity="false">
<appender-ref ref="Console"/>
<appender-ref ref="msdpRolling"/>
</AsyncLogger>
<AsyncLogger name="com.tansun" level="${LOGGER_LEVEL}" additivity="false">
<appender-ref ref="Console"/>
<appender-ref ref="projectRolling"/>
<appender-ref ref="projectErrorRolling"/>
</AsyncLogger>
<AsyncLogger name="com.bigtreefinance" level="${LOGGER_LEVEL}" additivity="false">
<appender-ref ref="Console"/>
<appender-ref ref="projectRolling"/>
<appender-ref ref="projectErrorRolling"/>
</AsyncLogger>
<-- 添加我们自己的apender到下面,注意这里不能使用异步,否则Skywalking控制台仍然无法看到日志信息 -->
<Logger name="com.bigtreefinance.invoice" level="${LOGGER_LEVEL}" additivity="false">
<appender-ref ref="Console"/>
<appender-ref ref="projectRolling"/>
<appender-ref ref="projectErrorRolling"/>
<appender-ref ref="SkywalkingLog"/>
</Logger>
<AsyncRoot level="${LOGGER_LEVEL}">
<appender-ref ref="Console"/>
<appender-ref ref="projectRolling" />
<appender-ref ref="projectErrorRolling" />
<-- 这里也注意加一下 -->
<appender-ref ref="SkywalkingLog"/>
</AsyncRoot>
</loggers>
</configuration>
解决方案二:我们实现slf4j的实现,取代log4j,然后我们在自己的实现中调用log4j和skywalking达到目的
注意,org.slf4j.impl下面的StaticLoggerBinder是固定写法,这是日志决定是使用log4j还是logback等的要点。
代码如下:
package org.slf4j.impl;
import com.bigtreefinance.core.log.NewLog4jLoggerFactory;
import org.slf4j.ILoggerFactory;
import org.slf4j.spi.LoggerFactoryBinder;
/**
* @author wangguodong
*/
public class StaticLoggerBinder
implements LoggerFactoryBinder {
public static String REQUESTED_API_VERSION = "1.6";
private static final String LOGGER_FACTORY_CLASS_STR = NewLog4jLoggerFactory.class.getName();
private static final StaticLoggerBinder SINGLETON = new StaticLoggerBinder();
private final ILoggerFactory loggerFactory = new NewLog4jLoggerFactory();
private StaticLoggerBinder() {
}
public static StaticLoggerBinder getSingleton() {
return SINGLETON;
}
@Override
public ILoggerFactory getLoggerFactory() {
return this.loggerFactory;
}
@Override
public String getLoggerFactoryClassStr() {
return LOGGER_FACTORY_CLASS_STR;
}
}
package org.slf4j.impl;
import org.apache.logging.slf4j.Log4jMarkerFactory;
import org.slf4j.IMarkerFactory;
import org.slf4j.spi.MarkerFactoryBinder;
public class StaticMarkerBinder implements MarkerFactoryBinder {
public static final StaticMarkerBinder SINGLETON = new StaticMarkerBinder();
private final IMarkerFactory markerFactory = new Log4jMarkerFactory();
public StaticMarkerBinder() {
}
@Override
public IMarkerFactory getMarkerFactory() {
return this.markerFactory;
}
@Override
public String getMarkerFactoryClassStr() {
return Log4jMarkerFactory.class.getName();
}
}
package org.slf4j.impl;
import org.apache.logging.slf4j.Log4jMDCAdapter;
import org.slf4j.spi.MDCAdapter;
public class StaticMDCBinder {
public static final StaticMDCBinder SINGLETON = new StaticMDCBinder();
private StaticMDCBinder() {
}
public MDCAdapter getMDCA() {
return new Log4jMDCAdapter();
}
public String getMDCAdapterClassStr() {
return Log4jMDCAdapter.class.getName();
}
}
package com.bigtreefinance.core.log;
import org.apache.logging.log4j.message.FormattedMessage;
import org.apache.logging.log4j.spi.ExtendedLogger;
import org.apache.logging.slf4j.Log4jLogger;
import org.apache.skywalking.apm.toolkit.trace.ActiveSpan;
import org.slf4j.Marker;
import org.slf4j.spi.LocationAwareLogger;
import java.io.Serializable;
public class NewLog4jLogger implements LocationAwareLogger, Serializable {
private Log4jLogger log4jLogger;
public NewLog4jLogger(ExtendedLogger logger, String name) {
log4jLogger = new Log4jLogger(logger, name);
}
@Override
public void log(Marker marker, String s, int i, String s1, Object[] objects, Throwable throwable) {
log4jLogger.log(marker, s, i, s1, objects, throwable);
}
@Override
public String getName() {
return log4jLogger.getName();
}
@Override
public boolean isTraceEnabled() {
return log4jLogger.isTraceEnabled();
}
@Override
public void trace(String s) {
log4jLogger.trace(s);
}
@Override
public void trace(String s, Object o) {
log4jLogger.trace(s, o);
}
@Override
public void trace(String s, Object o, Object o1) {
log4jLogger.trace(s, o, o1);
}
@Override
public void trace(String s, Object... objects) {
log4jLogger.trace(s, objects);
}
@Override
public void trace(String s, Throwable throwable) {
log4jLogger.trace(s, throwable);
}
@Override
public boolean isTraceEnabled(Marker marker) {
return log4jLogger.isTraceEnabled(marker);
}
@Override
public void trace(Marker marker, String s) {
log4jLogger.trace(marker, s);
}
@Override
public void trace(Marker marker, String s, Object o) {
log4jLogger.trace(marker, s, o);
}
@Override
public void trace(Marker marker, String s, Object o, Object o1) {
log4jLogger.trace(marker, s, o, o1);
}
@Override
public void trace(Marker marker, String s, Object... objects) {
log4jLogger.trace(marker, s, objects);
}
@Override
public void trace(Marker marker, String s, Throwable throwable) {
log4jLogger.trace(marker, s, throwable);
}
@Override
public boolean isDebugEnabled() {
return log4jLogger.isDebugEnabled();
}
@Override
public void debug(String s) {
log4jLogger.debug(s);
ActiveSpan.debug(s);
}
@Override
public void debug(String s, Object o) {
log4jLogger.debug(s, o);
ActiveSpan.info(new FormattedMessage(s, o).getFormattedMessage());
}
@Override
public void debug(String s, Object o, Object o1) {
log4jLogger.debug(s, o, o1);
ActiveSpan.info(new FormattedMessage(s, o, o1).getFormattedMessage());
}
@Override
public void debug(String s, Object... objects) {
log4jLogger.debug(s, objects);
ActiveSpan.info(new FormattedMessage(s, objects).getFormattedMessage());
}
@Override
public void debug(String s, Throwable throwable) {
log4jLogger.debug(s, throwable);
}
@Override
public boolean isDebugEnabled(Marker marker) {
return log4jLogger.isDebugEnabled(marker);
}
@Override
public void debug(Marker marker, String s) {
log4jLogger.debug(marker, s);
}
@Override
public void debug(Marker marker, String s, Object o) {
log4jLogger.debug(marker, s, o);
}
@Override
public void debug(Marker marker, String s, Object o, Object o1) {
log4jLogger.debug(marker, s, o, o1);
}
@Override
public void debug(Marker marker, String s, Object... objects) {
log4jLogger.debug(marker, s, objects);
}
@Override
public void debug(Marker marker, String s, Throwable throwable) {
log4jLogger.debug(marker, s, throwable);
}
@Override
public boolean isInfoEnabled() {
return log4jLogger.isInfoEnabled();
}
@Override
public void info(String s) {
log4jLogger.info(s);
ActiveSpan.info(s);
}
@Override
public void info(String s, Object o) {
log4jLogger.info(s, o);
ActiveSpan.info(new FormattedMessage(s, o).getFormattedMessage());
}
@Override
public void info(String s, Object o, Object o1) {
log4jLogger.info(s, o, o1);
ActiveSpan.info(new FormattedMessage(s, o, o1).getFormattedMessage());
}
@Override
public void info(String s, Object... objects) {
log4jLogger.info(s, objects);
ActiveSpan.info(new FormattedMessage(s, objects).getFormattedMessage());
}
@Override
public void info(String s, Throwable throwable) {
log4jLogger.info(s, throwable);//{},o,o
ActiveSpan.info(new FormattedMessage(s, throwable).getFormattedMessage());
}
@Override
public boolean isInfoEnabled(Marker marker) {
return log4jLogger.isInfoEnabled(marker);
}
@Override
public void info(Marker marker, String s) {
log4jLogger.info(marker, s);
}
@Override
public void info(Marker marker, String s, Object o) {
log4jLogger.info(marker, s, o);
}
@Override
public void info(Marker marker, String s, Object o, Object o1) {
log4jLogger.info(marker, s, o, o1);
}
@Override
public void info(Marker marker, String s, Object... objects) {
log4jLogger.info(marker, s, objects);
}
@Override
public void info(Marker marker, String s, Throwable throwable) {
log4jLogger.info(marker, s, throwable);
}
@Override
public boolean isWarnEnabled() {
return log4jLogger.isWarnEnabled();
}
@Override
public void warn(String s) {
log4jLogger.warn(s);
}
@Override
public void warn(String s, Object o) {
log4jLogger.warn(s, o);
}
@Override
public void warn(String s, Object... objects) {
log4jLogger.warn(s, objects);
}
@Override
public void warn(String s, Object o, Object o1) {
log4jLogger.warn(s, o, o1);
}
@Override
public void warn(String s, Throwable throwable) {
log4jLogger.warn(s, throwable);
}
@Override
public boolean isWarnEnabled(Marker marker) {
return log4jLogger.isWarnEnabled(marker);
}
@Override
public void warn(Marker marker, String s) {
log4jLogger.warn(marker, s);
}
@Override
public void warn(Marker marker, String s, Object o) {
log4jLogger.warn(marker, s, o);
}
@Override
public void warn(Marker marker, String s, Object o, Object o1) {
log4jLogger.warn(marker, s, o, o1);
}
@Override
public void warn(Marker marker, String s, Object... objects) {
log4jLogger.warn(marker, s, objects);
}
@Override
public void warn(Marker marker, String s, Throwable throwable) {
log4jLogger.warn(marker, s, throwable);
}
@Override
public boolean isErrorEnabled() {
return log4jLogger.isErrorEnabled();
}
@Override
public void error(String s) {
log4jLogger.error(s);
ActiveSpan.error(s);
}
@Override
public void error(String s, Object o) {
log4jLogger.error(s, o);
ActiveSpan.error(new FormattedMessage(s, o).getFormattedMessage());
}
@Override
public void error(String s, Object o, Object o1) {
log4jLogger.error(s, o, o1);
ActiveSpan.error(new FormattedMessage(s, o, o1).getFormattedMessage());
}
@Override
public void error(String s, Object... objects) {
log4jLogger.error(s, objects);
ActiveSpan.error(new FormattedMessage(s, objects).getFormattedMessage());
}
@Override
public void error(String s, Throwable throwable) {
log4jLogger.error(s, throwable);
ActiveSpan.error(s);
ActiveSpan.error(throwable);
}
@Override
public boolean isErrorEnabled(Marker marker) {
return log4jLogger.isErrorEnabled(marker);
}
@Override
public void error(Marker marker, String s) {
log4jLogger.error(marker, s);
}
@Override
public void error(Marker marker, String s, Object o) {
log4jLogger.error(marker, s, o);
}
@Override
public void error(Marker marker, String s, Object o, Object o1) {
log4jLogger.error(marker, s, o, o1);
}
@Override
public void error(Marker marker, String s, Object... objects) {
log4jLogger.error(marker, s, objects);
}
@Override
public void error(Marker marker, String s, Throwable throwable) {
log4jLogger.error(marker, s, throwable);
}
}
package com.bigtreefinance.core.log;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.spi.AbstractLoggerAdapter;
import org.apache.logging.log4j.spi.LoggerContext;
import org.apache.logging.log4j.util.StackLocatorUtil;
import org.slf4j.ILoggerFactory;
import org.slf4j.Logger;
/**
* @author wangguodong
*/
public class NewLog4jLoggerFactory extends AbstractLoggerAdapter<Logger> implements ILoggerFactory {
private static final String FQCN = NewLog4jLoggerFactory.class.getName();
private static final String PACKAGE = "org.slf4j";
public NewLog4jLoggerFactory() {
}
@Override
protected Logger newLogger(String name, LoggerContext context) {
String key = "ROOT".equals(name) ? "" : name;
return new NewLog4jLogger(context.getLogger(key), name);
}
@Override
protected LoggerContext getContext() {
Class<?> anchor = StackLocatorUtil.getCallerClass(FQCN, "org.slf4j");
return anchor == null ? LogManager.getContext() : this.getContext(StackLocatorUtil.getCallerClass(anchor));
}
}
运行项目,我们会看到这样的情景,但是不要慌:
没错,这里加载了两个StaticLoggerBinder这不会影响到项目的启动,只是提醒你有冲突,但是只会加载第一个被加载到的类!所以在pom文件中需要将我们自己写的类的包移动到log4j的上面,这是基于maven的最短路径加载的顺序。
总结
上述两种方案,都是需要有所改动,一个是调整log4j的xml配置文件,一个是调整pom文件,如果您有更好的方案,请留言告诉我。