关于Java日志隔离功能的闲谈

发表于 更新于 分类于 阅读次数： 本文字数： 9k 阅读时长 ≈ 15 分钟

背景

​ 我们都知道日志至于任何系统、软件都是十分重要的组成部分，通过日志我们可以方便地了解到现在系统运行是否正常、是否有异常情况。但有时候日志太多了也会有幸福地烦恼，发生异常想通过日志进行排查，可是满屏地日志都是不那么重要地内容，像心跳日志、debug日志等等。

​ 这在java应用尤为严重，你每引入地一个jar都有可能引入一堆打印的日志，这样一来要从日志中找到你所需要的内容将是一件极其困难的事情。当然，你会说，java拥有这么多优秀的日志框架系统，可以简单地通过相应地配置文件将这些内容根据不同的输出级别输出到不同的目录文件，可是如果将这件事情都交给终端用户去处理，那将会是一件极其复杂的工程，他得明白哪些是他需要的、哪些是他不需要的，而这些信息应该是对应的开发人员最清楚不过的，因此让开发人员提前将这些日志进行归类，输出到指定的文件，那对应使用者来说将会变得很简单。

实现方法一

​ 首先想到的应该就是通过日志的配置文件，添加不同的appender和logger。可是这些配置文件应该是存在与用户的应用中的，作为一个被引入的module该如何去修改这份文件呢？而且用户最终采用的是哪个日志框架我同样不能左右，我该根据哪个实现呢？

​ 第一个问题，很好解决，现在大部分的日志框架都提供了基于java 代码的方式来添加appender和logger的配置，因此我们只需要在应用启动时，获取LoggerContext对象，然后添加自定义的appender和logger即可，例如阿里的TDDL中就有相关的实现：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
// slf4j只是一个代理工程，需要判断一下具体的实现类
if (checkLogger(logger, LOGBACK)) {
    if (canUseEncoder) {
        dynamic = new DynamicLogbackLogger();
    } else {
        dynamic = new DynamicLogback918Logger();
    }
} else if (checkLogger(logger, LOG4J_Adapter)) {
    dynamic = new DynamicLog4jAdapterLogger();
} else if (checkLogger(logger, LOG4J)) {
    dynamic = new DynamicLog4jLogger();
}  else {
    logger.warn("logger is not a log4j/logback instance, dynamic logger is disabled");
}

先判断具体地实现框架是哪个，然后再获得对应实现框架的loggerContext，例如logback：

1
2
3
4
5
6
7
8
9
10
11
12
if (loggerContext == null) {
    ILoggerFactory lcObject = LoggerFactory.getILoggerFactory();
    if (!(lcObject instanceof LoggerContext)) {
        throw new LogbackException("Expected LOGBACK binding with SLF4J, but another log system has taken the place: " + lcObject.getClass().getSimpleName());
    }
    loggerContext = (LoggerContext) lcObject;
    if (props != null) {
        for (Map.Entry<String, String> entry : props.entrySet()) {
            loggerContext.putProperty(entry.getKey(), entry.getValue());
        }
    }
}

接着再添加自身所需的appender和logger：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
protected Appender buildAppender(String name, String fileName, String pattern) {
	RollingFileAppender appender = new RollingFileAppender();
	appender.setContext(loggerContext);
	appender.setName(name);
	appender.setAppend(true);
	appender.setFile(new File(getLogPath(), fileName).getAbsolutePath());

	TimeBasedRollingPolicy rolling = new TimeBasedRollingPolicy();
	rolling.setContext(loggerContext);
	rolling.setParent(appender);
	rolling.setFileNamePattern(new File(getLogPath(), fileName).getAbsolutePath() + ".%d{yyyy-MM-dd}");
	rolling.start();
	appender.setRollingPolicy(rolling);

	PatternLayoutEncoder layout = new PatternLayoutEncoder();
	layout.setContext(loggerContext);
	layout.setPattern(pattern);
	layout.setCharset(Charset.forName(getEncoding()));
	layout.start();
	appender.setEncoder(layout);
	// 启动
	appender.start();
	return appender;
}

可是这样做，存在的问题也是很明显的：

  • 需自己判断应用采用的实现框架，但可以通过抽取的方式构建一个公共jar，例如common包
  • 该实现框架需要能够支持通过动态的形式添加appender
  • 仍然与应用的Log耦合在一起

那除此之外，还有其他的方式能够实现同样的功能吗？答案当时是有。

实现方法二

默认情况下一个应用启动后，只会存在一个loggerContext，因为日志框架都是单例模式的，也是为了减少开销。那如果我们有多个loggerContext呢，是不是可以每个需要的modeule都拥有一份单独的loggerContext，那不就可以通过加载配置文件的形式更轻量级地来实现需要动态添加appender的功能呢。

大致的实现逻辑应该是这样：

  • 需要一个map来管理所有的这些loggerContext，以每个module的groupId+artifactId（现在90%以上的工程都提供maven坐标）为唯一标识 – key
  • 每个module自身需要有一份配置文件，当然由于日志实现很多你可能需要多份文件，同样你可以定义自己的格式，然后通过java code的形式去转化为最终的各个不同实现
  • 需要能通过唯一的Id，例如groupId+artifactId定位到你的配置文件

这样大致的一个可以做到日志隔离的简单框架就搭建起来了，使用配置文件还有一个好处就是，一些日志框架可以动态刷新配置文件，这就使得你可以在运行时动态改变日志参数，例如日志级别。

获取一个单独的logger对象：

1
ModuleLoggerManager.getLoggerByCoordinate(name, "coordinate");

维护logger相关对象：

1
2
final ConcurrentHashMap<ModuleLogId, ModuleLogInfo> MODULE_LOGGER_MAP =
            new ConcurrentHashMap<>(8)
1
2
3
4
5
6
7
8
9
10
11
12
13
@Data
public class ModuleLogId {

    // 一些可修改的日志配置信息，可通过${key}的形式传递
    private final Map<String, String> tags = new HashMap<>(8);

    private final String              coordinate;

    public ModuleLogId addTag(String key, String value) {
        tags.put(key, value);
        return this;
    }
}
1
2
3
4
5
6
7
8
9
@NoArgsConstructor
public class ModuleLogInfo {
    @Getter
    @Setter
    // 根据具体实现会创建不同的loggerFactory对象，然后不同的logFactory对象会创建不同的loggerContext对象
    private AbstractLoggerModuleFactory abstractLoggerModuleFactory;
    @Getter
    private Properties properties = new Properties();
}

创建factory过程：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
private static AbstractLoggerModuleFactory createILoggerFactory(ModuleLogId moduleLogId, ClassLoader moduleClassLoader) {
	if (System.getProperty(Constants.Module_LOGGER_DISABLE_PROP_KEY) != null
			&& Boolean.TRUE.toString().equalsIgnoreCase(
			System.getProperty(Constants.Module_LOGGER_DISABLE_PROP_KEY))) {
		Constants.DEFAULT_LOGGER.warn("Module Logger is disabled!  -D{}=true", Constants.Module_LOGGER_DISABLE_PROP_KEY);
		return JVM_LOGGER_FACTORY;
	}
	// set log props
	LogTypeJudgeUtil.processGlobalSystemLogProperties();

	// do create
	try {
		// first log4j2
		if (LogTypeJudgeUtil.isLog4j2Usable(moduleClassLoader)) {
            ...
			return log4j2LoggerFactory;
		}

		//second logback
		if (LogTypeJudgeUtil.isLogbackUsable(moduleClassLoader)) {
			...
            return logbackLoggerFactory;
		}

		// third log4j
		if (LogTypeJudgeUtil.isLog4jUsable(moduleClassLoader)) {
			...
            return log4jLoggerFactory;
		}

		Constants.DEFAULT_LOGGER.warn("No log util is usable, Default app logger will be used.");
	} catch (Throwable e) {
		Constants.DEFAULT_LOGGER.error("Build ILoggerFactory error! Default app logger will be used.",
				e);
	}

	return JVM_LOGGER_FACTORY;
}

以log4j2为例，获取loggerFactory：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
/**
 * confFileUrl 为根据传入的coordinate以及具体的日志实现框架，拼接出路径
 * 例如 coordinate 为 org.jobshen.mq.rocketmq
 * 则 log4j2的文件路径为：classpath*:org/jobshen/mq/rocketmq/log/log4j2/log-conf.xml
 */
protected AbstractLoggerModuleFactory doBuild(final String coordinate, final ClassLoader moduleClassLoader, final URL confFileUrl) {
	try {
        //构建单独的loggerContext对象
		final LoggerContext context = new LoggerContext(coordinate, null, confFileUrl.toURI());
		Configuration config = null;
		ConfigurationFactory configurationFactory = ConfigurationFactory.getInstance();
		try {
			Class[] parameterTypes = new Class[3];
			parameterTypes[0] = String.class;
			parameterTypes[1] = URI.class;
			parameterTypes[2] = ClassLoader.class;
			Method getConfigurationMethod = configurationFactory.getClass().getMethod(
					"getConfiguration", parameterTypes);
			config = (Configuration) getConfigurationMethod.invoke(configurationFactory,
					coordinate, confFileUrl.toURI(), moduleClassLoader);
		} catch (NoSuchMethodException noSuchMethodException) {
			Class[] parameterTypes = new Class[4];
			parameterTypes[0] = LoggerContext.class;
			parameterTypes[1] = String.class;
			parameterTypes[2] = URI.class;
			parameterTypes[3] = ClassLoader.class;
			Method getConfigurationMethod = configurationFactory.getClass().getMethod(
					"getConfiguration", parameterTypes);
			config = (Configuration) getConfigurationMethod.invoke(configurationFactory,
					context, coordinate, confFileUrl.toURI(), moduleClassLoader);
		}
		if (config == null) {
			throw new RuntimeException("No log4j2 configuration are found.");
		}
		for (Map.Entry entry : getProperties().entrySet()) {
			//from Map<String,String>
			config.getProperties().put((String) entry.getKey(), (String) entry.getValue());
		}

		for (Map.Entry entry : System.getProperties().entrySet()) {
			//from Map<String,String>
			config.getProperties().put((String) entry.getKey(), (String) entry.getValue());
		}

		context.start(config);

		return new AbstractLoggerModuleFactory(getLoggingType()) {

			private ConcurrentMap<String, org.apache.logging.slf4j.Log4jLogger> loggerMap =
					new ConcurrentHashMap<>();

			@Override
			public Logger setLevel(String loggerName, ModuleLogLevel logLevel) {
				org.apache.logging.slf4j.Log4jLogger log4jLoggerAdapter = (org.apache.logging.slf4j.Log4jLogger) this
						.getLogger(loggerName);
				final String key = Logger.ROOT_LOGGER_NAME.equals(loggerName) ? LogManager.ROOT_LOGGER_NAME
						: loggerName;
				org.apache.logging.log4j.core.Logger log4j2Logger = context.getLogger(key);
				//level
				org.apache.logging.log4j.Level log4j2Level = this.toLog4j2Level(logLevel);
				log4j2Logger.setLevel(log4j2Level);
				return log4jLoggerAdapter;
			}

			@Override
            //使用门面框架 slf4j 返回logger对象
			public org.slf4j.Logger getLogger(String name) {
				final String key = Logger.ROOT_LOGGER_NAME.equals(name) ? LogManager.ROOT_LOGGER_NAME
						: name;
				org.apache.logging.log4j.core.Logger log4jLogger = context.getLogger(key);
				Log4jLogger oldInst = this.loggerMap.get(key);
				if (oldInst != null) {
					return oldInst;
				}
				Log4jLogger newInst = new Log4jLogger(log4jLogger, key);
				oldInst = this.loggerMap.putIfAbsent(key, newInst);
				return oldInst == null ? newInst : oldInst;
			}

			private org.apache.logging.log4j.Level toLog4j2Level(ModuleLogLevel logLevel) {
				if (logLevel == null) {
					throw new IllegalStateException(
							"ModuleLogLevel is NULL when adapter to log4j2.");
				}
				switch (logLevel) {
				case TRACE:
					return Level.TRACE;
				case DEBUG:
					return Level.DEBUG;
				case INFO:
					return Level.INFO;
				case WARN:
					return Level.WARN;
				case ERROR:
					return Level.ERROR;
				default:
					throw new IllegalStateException(logLevel
							+ " is unknown when adapter to log4j2.");
				}
			}
		};
	} catch (Throwable e) {
		throw new IllegalStateException("Log4j2 loggerModuleFactory build error!", e);
	}
}

当然这个方案也有其缺陷，loggerContext对象增加了对应的内存消耗也就增加了。简单统计了下，每增加一个采用日志隔离框架的模块，内存使用增加5~10kb。