msb-public
/
source-code-hunter
mirror of https://github.com/doocs/source-code-hunter.git
5
2
Code Issues Projects Releases Wiki Activity

fix: resolve content problem and close #77

Browse Source
pull/78/head
yanglbme 4 years ago
parent 1c62a708c0
commit d609c2daa6
1 changed files with 424 additions and 77 deletions
Show Stats Download Patch File Download Diff File

501
docs/SpringBoot/SpringBoot-LogSystem.md
Unescape View File

@ -1,109 +1,456 @@
该文所涉及的 netty 源码版本为 4.1.6。
# SpringBoot 日志系统
## Netty 中的 ByteBuf 为什么会发生内存泄漏
- Author: [HuiFer](https://github.com/huifer)
- 源码阅读仓库: [SourceHot-spring-boot](https://github.com/SourceHot/spring-boot-read)
在 Netty 中，ByetBuf 并不是只采用可达性分析来对 ByteBuf 底层的 byte[]数组来进行垃圾回收，而同时采用引用计数法来进行回收，来保证堆外内存的准确时机的释放。
在每个 ByteBuf 中都维护着一个 refCnt 用来对 ByteBuf 的被引用数进行记录，当 ByteBuf 的 retain()方法被调用时，将会增加 refCnt 的计数，而其 release()方法被调用时将会减少其被引用数计数。
- 包路径: `org.springframework.boot.logging`
## 日志级别
- 日志级别: `org.springframework.boot.logging.LogLevel`
```java
private boolean release0(int decrement) {
for (;;) {
int refCnt = this.refCnt;
if (refCnt < decrement) {
throw new IllegalReferenceCountException(refCnt, -decrement);
}
if (refCntUpdater.compareAndSet(this, refCnt, refCnt - decrement)) {
if (refCnt == decrement) {
deallocate();
return true;
}
return false;
}
}
public enum LogLevel {
TRACE, DEBUG, INFO, WARN, ERROR, FATAL, OFF
}
```
当调用了 ByteBuf 的 release()方法的时候，最后在上方的 release0()方法中将会为 ByteBuf 的引用计数减一，当引用计数归于 0 的时候，将会调用 deallocate()方法对其对应的底层存储数组进行释放(在池化的 ByteBuf 中，在 deallocate()方法里会把该 ByteBuf 的 byte[]回收到底层内存池中，以确保 byte[]可以重复利用)。
由于 Netty 中的 ByteBuf 并不是随着申请之后会马上使其引用计数归 0 而进行释放，往往在这两个操作之间还有许多操作，如果在这其中如果发生异常抛出导致引用没有及时释放，在使用池化 ByetBuffer 的情况下内存泄漏的问题就会产生。
当采用了池化的 ByteBuffer 的时候，比如 PooledHeapByteBuf 和 PooledDirectByteBuf，其 deallocate()方法一共主要分为两个步骤。
## java 日志实现
```java
@Override
protected final void deallocate() {
if (handle >= 0) {
final long handle = this.handle;
this.handle = -1;
memory = null;
chunk.arena.free(chunk, handle, maxLength);
recycle();
- `org.springframework.boot.logging.java.JavaLoggingSystem`
![image-20200323144523848](../../images/SpringBoot/image-20200323144523848.png)
```JAVA
static {
// KEY : springBoot 定义的日志级别, value: jdk 定义的日志级别
LEVELS.map(LogLevel.TRACE, Level.FINEST);
LEVELS.map(LogLevel.DEBUG, Level.FINE);
LEVELS.map(LogLevel.INFO, Level.INFO);
LEVELS.map(LogLevel.WARN, Level.WARNING);
LEVELS.map(LogLevel.ERROR, Level.SEVERE);
LEVELS.map(LogLevel.FATAL, Level.SEVERE);
LEVELS.map(LogLevel.OFF, Level.OFF);
}
}
```
- 将其底层的 byte[]通过 free()方法回收到内存池中等待下一次使用。
- 通过 recycle()方法将其本身回收到对象池中等待下一次使用。
关键在第一步的内存回收到池中，如果其引用计数未能在 ByteBuf 对象被回收之前归 0，将会导致其底层占用 byte[]无法回收到内存池 PoolArena 中，导致该部分无法被重复利用，下一次将会申请新的内存进行操作，从而产生内存泄漏。
而非池化的 ByteBuffer 即使引用计数没有在对象被回收的时候被归 0，因为其使用的是单独一块 byte[]内存，因此也会随着 java 对象被回收使得底层 byte[]被释放（由 JDK 的 Cleaner 来保证）。
- LEVELS 对象
```java
protected static class LogLevels<T> {
/**
* key ： SpringBoot 中定义的日志级别, value: 其他日志框架的日志级别
*/
private final Map<LogLevel, T> systemToNative;
/**
* key : 其他日志框架的日志级别 , value: springBoot 中定义中定义的日志级别
*/
private final Map<T, LogLevel> nativeToSystem;
}
```
## LoggingSystem
- 抽象类
- `org.springframework.boot.logging.LoggingSystem`
- 一个 map 对象: `SYSTEMS`
```JAVA
/**
* key: 第三方日志框架的类 value: springBoot 中的处理类
*/
private static final Map<String, String> SYSTEMS;
static {
Map<String, String> systems = new LinkedHashMap<>();
systems.put("ch.qos.logback.core.Appender", "org.springframework.boot.logging.logback.LogbackLoggingSystem");
systems.put("org.apache.logging.log4j.core.impl.Log4jContextFactory",
"org.springframework.boot.logging.log4j2.Log4J2LoggingSystem");
systems.put("java.util.logging.LogManager", "org.springframework.boot.logging.java.JavaLoggingSystem");
SYSTEMS = Collections.unmodifiableMap(systems);
}
```
- 各个抽象方法
## Netty 进行内存泄漏检测的原理
| 方法名称 | 作用 |
| ----------------------- | ---------------------------------- |
| beforeInitialize | 初始化之前调用，目的是减少日志输出 |
| initialize | 初始化日志 |
| cleanUp | 清除日志 |
| getShutdownHandler | |
| getSupportedLogLevels | 获取支持的日志级别 |
| setLogLevel | 设置日志级别 |
| getLoggerConfigurations | 获取日志配置 |
在 Netty 对于 ByteBuf 的检测中，一共包含 4 个级别。
### get
```java
if (level.ordinal() < Level.PARANOID.ordinal()) {
if (leakCheckCnt ++ % samplingInterval == 0) {
reportLeak(level);
return new DefaultResourceLeak(obj);
} else {
return null;
public static LoggingSystem get(ClassLoader classLoader) {
// 获取系统属性
String loggingSystem = System.getProperty(SYSTEM_PROPERTY);
if (StringUtils.hasLength(loggingSystem)) {
// 是不是NONE
if (NONE.equals(loggingSystem)) {
// 空的日志系统
return new NoOpLoggingSystem();
}
return get(classLoader, loggingSystem);
}
// 循环所有日志,
return SYSTEMS.entrySet().stream().filter((entry) -> ClassUtils.isPresent(entry.getKey(), classLoader))
.map((entry) ->
// 实例化具体日志
get(classLoader, entry.getValue())).findFirst()
.orElseThrow(() -> new IllegalStateException("No suitable logging system located"));
}
}
```
以默认的 SIMPLE 级别为例，在这个级别下，Netty 将会根据以 ByteBuf 创建的序列号与 113 进行取模来判断是否需要进行内存泄漏的检测追踪。当取模成功的时候，将会为这个 ByteBuf 产生一个对应的 DefaultResourceLeak 对象，DefaultResourceLeak 是一个 PhantomReference 虚引用的子类，并有其对应的 ReferenceQueue。之后通过 SimpleLeakAwareByteBuf 类来将被追踪的 ByteBuf 和 DefaultResourceLeak 包装起来。
- 实例化日志系统
```java
@Override
public boolean release(int decrement) {
boolean deallocated = super.release(decrement);
if (deallocated) {
leak.close();
private static LoggingSystem get(ClassLoader classLoader, String loggingSystemClass) {
try {
Class<?> systemClass = ClassUtils.forName(loggingSystemClass, classLoader);
Constructor<?> constructor = systemClass.getDeclaredConstructor(ClassLoader.class);
constructor.setAccessible(true);
return (LoggingSystem) constructor.newInstance(classLoader);
}
catch (Exception ex) {
throw new IllegalStateException(ex);
}
}
return deallocated;
}
```
在包装类中，如果该 ByteBuf 成功 deallocated 释放掉了其持有的 byte[]数组将会调用 DefaultResourceLeak 的 close()方法来已通知当前 ByteBuf 已经释放了其持有的内存。
正是这个虚引用使得该 DefaultResourceLeak 对象被回收的时候将会被放入到与这个虚引用所对应的 ReferenceQueue 中。
![image-20200323151409473](../../images/SpringBoot/image-20200323151409473.png)
- 默认日志: `org.springframework.boot.logging.logback.LogbackLoggingSystem`
### beforeInitialize
- 初始化之前
![image-20200323154205484](../../images/SpringBoot/image-20200323154205484.png)
- 链路
1. `org.springframework.boot.context.logging.LoggingApplicationListener#onApplicationEvent`
2. `org.springframework.boot.context.logging.LoggingApplicationListener#onApplicationStartingEvent`
3. `org.springframework.boot.logging.LoggingSystem#beforeInitialize`
- 因为前文中我们已知对象是：`org.springframework.boot.logging.logback.LogbackLoggingSystem` 直接看这个类的**`beforeInitialize`**方法
```JAVA
@Override
public void beforeInitialize() {
// 日志上下文
LoggerContext loggerContext = getLoggerContext();
// 是否初始化
if (isAlreadyInitialized(loggerContext)) {
return;
}
// 父类方法
super.beforeInitialize();
// 添加过滤器
loggerContext.getTurboFilterList().add(FILTER);
}
```
- 初始化之前的的操作完成了初始化方法开始
### initialize
- `org.springframework.boot.context.logging.LoggingApplicationListener#onApplicationEnvironmentPreparedEvent`
```JAVA
private void onApplicationEnvironmentPreparedEvent(ApplicationEnvironmentPreparedEvent event) {
if (this.loggingSystem == null) {
this.loggingSystem = LoggingSystem.get(event.getSpringApplication().getClassLoader());
}
initialize(event.getEnvironment(), event.getSpringApplication().getClassLoader());
}
```
- `org.springframework.boot.context.logging.LoggingApplicationListener#initializeSystem`
```JAVA
protected void initialize(ConfigurableEnvironment environment, ClassLoader classLoader) {
new LoggingSystemProperties(environment).apply();
this.logFile = LogFile.get(environment);
if (this.logFile != null) {
this.logFile.applyToSystemProperties();
}
this.loggerGroups = new LoggerGroups(DEFAULT_GROUP_LOGGERS);
// 早期 的日志级别
initializeEarlyLoggingLevel(environment);
// 初始化日志系统
initializeSystem(environment, this.loggingSystem, this.logFile);
// 初始化日志级别
initializeFinalLoggingLevels(environment, this.loggingSystem);
registerShutdownHookIfNecessary(environment, this.loggingSystem);
}
```
```JAVA
private void initializeSystem(ConfigurableEnvironment environment, LoggingSystem system, LogFile logFile) {
LoggingInitializationContext initializationContext = new LoggingInitializationContext(environment);
String logConfig = environment.getProperty(CONFIG_PROPERTY);
if (ignoreLogConfig(logConfig)) {
// 日志系统初始化
system.initialize(initializationContext, null, logFile);
}
else {
try {
ResourceUtils.getURL(logConfig).openStream().close();
system.initialize(initializationContext, logConfig, logFile);
}
catch (Exception ex) {
// NOTE: We can't use the logger here to report the problem
System.err.println("Logging system failed to initialize using configuration from '" + logConfig + "'");
ex.printStackTrace(System.err);
throw new IllegalStateException(ex);
}
}
}
```
- `org.springframework.boot.logging.logback.LogbackLoggingSystem#initialize`
```java
DefaultResourceLeak ref = (DefaultResourceLeak) refQueue.poll();
if (ref == null) {
break;
}
@Override
public void initialize(LoggingInitializationContext initializationContext, String configLocation, LogFile logFile) {
LoggerContext loggerContext = getLoggerContext();
if (isAlreadyInitialized(loggerContext)) {
return;
}
// 日志初始化
super.initialize(initializationContext, configLocation, logFile);
loggerContext.getTurboFilterList().remove(FILTER);
markAsInitialized(loggerContext);
if (StringUtils.hasText(System.getProperty(CONFIGURATION_FILE_PROPERTY))) {
getLogger(LogbackLoggingSystem.class.getName()).warn("Ignoring '" + CONFIGURATION_FILE_PROPERTY
+ "' system property. Please use 'logging.config' instead.");
}
}
```
ref.clear();
- `org.springframework.boot.logging.AbstractLoggingSystem#initializeWithConventions`
if (!ref.close()) {
continue;
}
```JAVA
private void initializeWithConventions(LoggingInitializationContext initializationContext, LogFile logFile) {
String config = getSelfInitializationConfig();
if (config != null && logFile == null) {
// self initialization has occurred, reinitialize in case of property changes
reinitialize(initializationContext);
return;
}
if (config == null) {
config = getSpringInitializationConfig();
}
if (config != null) {
loadConfiguration(initializationContext, config, logFile);
return;
}
// 加载默认配置
loadDefaults(initializationContext, logFile);
}
```
- `org.springframework.boot.logging.logback.LogbackLoggingSystem#loadDefaults`
```JAVA
@Override
protected void loadDefaults(LoggingInitializationContext initializationContext, LogFile logFile) {
LoggerContext context = getLoggerContext();
stopAndReset(context);
boolean debug = Boolean.getBoolean("logback.debug");
if (debug) {
StatusListenerConfigHelper.addOnConsoleListenerInstance(context, new OnConsoleStatusListener());
}
LogbackConfigurator configurator = debug ? new DebugLogbackConfigurator(context)
: new LogbackConfigurator(context);
Environment environment = initializationContext.getEnvironment();
context.putProperty(LoggingSystemProperties.LOG_LEVEL_PATTERN,
environment.resolvePlaceholders("${logging.pattern.level:${LOG_LEVEL_PATTERN:%5p}}"));
context.putProperty(LoggingSystemProperties.LOG_DATEFORMAT_PATTERN, environment.resolvePlaceholders(
"${logging.pattern.dateformat:${LOG_DATEFORMAT_PATTERN:yyyy-MM-dd HH:mm:ss.SSS}}"));
context.putProperty(LoggingSystemProperties.ROLLING_FILE_NAME_PATTERN, environment
.resolvePlaceholders("${logging.pattern.rolling-file-name:${LOG_FILE}.%d{yyyy-MM-dd}.%i.gz}"));
new DefaultLogbackConfiguration(initializationContext, logFile).apply(configurator);
context.setPackagingDataEnabled(true);
}
```
String records = ref.toString();
if (reportedLeaks.putIfAbsent(records, Boolean.TRUE) == null) {
if (records.isEmpty()) {
logger.error("LEAK: {}.release() was not called before it's garbage-collected. " +
"Enable advanced leak reporting to find out where the leak occurred. " +
"To enable advanced leak reporting, " +
"specify the JVM option '-D{}={}' or call {}.setLevel()",
resourceType, PROP_LEVEL, Level.ADVANCED.name().toLowerCase(), simpleClassName(this));
} else {
logger.error(
"LEAK: {}.release() was not called before it's garbage-collected.{}",
resourceType, records);
```JAVA
@Override
public void initialize(LoggingInitializationContext initializationContext, String configLocation, LogFile logFile) {
LoggerContext loggerContext = getLoggerContext();
// 是否加载过
if (isAlreadyInitialized(loggerContext)) {
return;
}
// 日志初始化
super.initialize(initializationContext, configLocation, logFile);
// 删除 FILTER
loggerContext.getTurboFilterList().remove(FILTER);
// 初始化标记
markAsInitialized(loggerContext);
if (StringUtils.hasText(System.getProperty(CONFIGURATION_FILE_PROPERTY))) {
getLogger(LogbackLoggingSystem.class.getName()).warn("Ignoring '" + CONFIGURATION_FILE_PROPERTY
+ "' system property. Please use 'logging.config' instead.");
}
}
}
```
Netty 会在下一次 ByteBuf 的采样中通过 reportLeak()方法将 ReferenceQueue 中的 DefaultResourceLeak 取出并判断其对应的 ByteBuf 是否已经在其回收前调用过其 close()方法，如果没有，显然在池化 ByteBuf 的场景下内存泄漏已经产生，将会以 ERROR 日志的方式进行日志打印。
标记`markAsInitialized`
```JAVA
private void markAsInitialized(LoggerContext loggerContext) {
loggerContext.putObject(LoggingSystem.class.getName(), new Object());
}
```
此时日志初始化完成
### 默认配置文件
- `getStandardConfigLocations` 这个方法定义了默认配置文件有哪些
```java
@Override
protected String[] getStandardConfigLocations() {
return new String[] { "logback-test.groovy", "logback-test.xml", "logback.groovy", "logback.xml" };
}
```
- 切回`org.springframework.boot.logging.AbstractLoggingSystem#initializeWithConventions`方法
- 添加依赖
```XML
<dependency>
<groupId>org.springframework.boot</groupId>
<artifactId>spring-boot-starter-logging</artifactId>
<version>${revision}</version>
</dependency>
```
- 添加配置文件
![image-20200323161442058](../../images/SpringBoot/image-20200323161442058.png)
![image-20200323161522570](../../images/SpringBoot/image-20200323161522570.png)
- 此时配置文件地址出现了
```JAVA
protected String getSelfInitializationConfig() {
// 寻找配置文件
return findConfig(getStandardConfigLocations());
}
```
```JAVA
@Override
protected String[] getStandardConfigLocations() {
return new String[] { "logback-test.groovy", "logback-test.xml", "logback.groovy", "logback.xml" };
}
```
```JAVA
private String findConfig(String[] locations) {
for (String location : locations) {
ClassPathResource resource = new ClassPathResource(location, this.classLoader);
if (resource.exists()) {
return "classpath:" + location;
}
}
return null;
}
```
- 此时自定义配置文件如何获取的已经明了
#### reinitialize
```JAVA
@Override
protected void reinitialize(LoggingInitializationContext initializationContext) {
// 日志上下文重新设置
getLoggerContext().reset();
getLoggerContext().getStatusManager().clear();
// 加载配置文件
loadConfiguration(initializationContext, getSelfInitializationConfig(), null);
}
```
```JAVA
@Override
protected void loadConfiguration(LoggingInitializationContext initializationContext, String location,
LogFile logFile) {
// 父类方法
super.loadConfiguration(initializationContext, location, logFile);
// 获取上下文
LoggerContext loggerContext = getLoggerContext();
// 停止并且重启
stopAndReset(loggerContext);
try {
// 配置文件加载
configureByResourceUrl(initializationContext, loggerContext, ResourceUtils.getURL(location));
}
catch (Exception ex) {
throw new IllegalStateException("Could not initialize Logback logging from " + location, ex);
}
List<Status> statuses = loggerContext.getStatusManager().getCopyOfStatusList();
StringBuilder errors = new StringBuilder();
for (Status status : statuses) {
if (status.getLevel() == Status.ERROR) {
errors.append((errors.length() > 0) ? String.format("%n") : "");
errors.append(status.toString());
}
}
if (errors.length() > 0) {
throw new IllegalStateException(String.format("Logback configuration error detected: %n%s", errors));
}
}
```
```java
private void configureByResourceUrl(LoggingInitializationContext initializationContext, LoggerContext loggerContext,
URL url) throws JoranException {
if (url.toString().endsWith("xml")) {
// logback 日志操作
JoranConfigurator configurator = new SpringBootJoranConfigurator(initializationContext);
// 设置上下文
configurator.setContext(loggerContext);
// 执行配置
configurator.doConfigure(url);
}
else {
new ContextInitializer(loggerContext).configureByResource(url);
}
}
```
以上内容可以结合 JVM 堆外内存的资料进行阅读。
- 执行配置属于 logback 操作源码不在此进行分析

Write Preview
Loading…
Cancel
Save