判断程序员是否合格条件之一：看他解决突发问题的能力！

本文要介绍的是一个发生在我们线上环境的真实案例，问题发生在某次大促期间，对我们的线上集群造成了比较大的影响，这篇文章简单复盘一下这个问题。

为了方便大家理解，实际排查和解决过程可能和本文描述的并不完全一致，但是思路是一样的。

一、问题过程

某次大促期间，某一个线上应用突然发生大量报警，提示磁盘占用率过高，一度达到了80%多。

这种情况我们第一时间登录线上机器，查看线上机器的磁盘使用情况。使用命令：df查看磁盘占用情况。

$df

Filesystem 1K-blocks Used Available Use% Mounted on

/ 62914560 58911440 4003120 93% /

/dev/sda2 62914560 58911440 4003120 93% /home/admin

发现机器磁盘确实耗费的比较严重，因为大促期间请求量比较多，于是我们最先开始怀疑是不是日志太多了，导致磁盘耗尽。

这里插播一个背景，我们的线上机器是配置了日志的自动压缩和清理的，单个文件达到一定的大小，或者机器内容达到一定的阈值之后，就会自动触发。

但是大促当天并没有触发日志的清理，导致机器磁盘一度被耗尽。

经过排查，我们发现是应用的某一些Log文件，占用了极大的磁盘空间，并且还在不断的增大。

du -sm * | sort -nr

512 service.log.20201105193331

256 service.log

428 service.log.20201106151311

286 service.log.20201107195011

356 service.log.20201108155838

du -sm * | sort -nr ：统计当前目录下文件大小，并按照大小排序代码文本框

于是经过和运维同学沟通，我们决定进行紧急处理。

首先采取的手段就是手动清理日志文件，运维同学登录到服务器上面之后，手动的清理了一些不太重要的日志文件。

rm service.log.20201105193331

但是执行了清理命令之后，发现机器上面的磁盘使用率并没有减少，而且还是在不断的增加。

$df

Filesystem 1K-blocks Used Available Use% Mounted on

/ 62914560 58911440 4003120 93% /

/dev/sda2 62914560 58911440 4003120 93% /home/admin

于是我们开始排查为什么日志被删除之后，内存空间没有被释放，通过命令，我们查到了是有一个进程还在对文件进行读取。

lsof |grep deleted

SLS 11526 root 3r REG 253,0 2665433605 104181296 /home/admin/****/service.log.20201205193331 (deleted)

lsof |grep deleted 的作用是：查看所有已打开文件并筛选出其中已删除状态的文件

经过排查，这个进程是一个SLS进程，在不断的从机器上读取日志内容。

LS是阿里的一个日志服务，提供一站式提供数据收集、清洗、分析、可视化和告警功能。简单点说就是会把服务器上面的日志采集到，持久化，然后供查询、分析等。

我们线上日志都会通过SLS进行采集，所以，通过分析，我们发现磁盘空间没释放，和SLS的日志读取有关。

到这里，问题基本已经定位到了，那么我们插播一下原理，介绍一下这背后的背景知识。

二、背景知识

Linux系统中是通过link的数量来控制文件删除的，只有当一个文件不存在任何link的时候，这个文件才会被删除。

一般来说，每个文件都有2个link计数器:i_count 和 i_nlink，也就是说：Linux系统中只有i_nlink及i_count都为0的时候，这个文件才会真正被删除。

i_count表示当前文件使用者(或被调用)的数量,

i_nlink表示介质连接的数量(硬链接的数量);

可以理解为i_count是内存引用计数器，i_nlink是磁盘的引用计数器。

当一个文件被某一个进程引用时，对应i_count数就会增加;当创建文件的硬链接的时候，对应i_nlink数就会增加。

在Linux或者Unix系统中，通过rm或者文件管理器删除文件，只是将它会从文件系统的目录结构上解除链接(unlink)，实际上就是减少磁盘引用计数i_nlink，但是并不会减少i_count数。

如果一个文件正在被某个进程调用，用户使用rm命令把文件"删除"了，这时候通过ls等文件管理命令就无法找到这个文件了，但是并不意味着这个文件真正的从磁盘上删除了。

因为还有一个进程在正常的执行，在向文件中读取或写入，也就是说文件其实并没有被真正的"删除"，所以磁盘空间也就会一直被占用。

而我们的线上问题就是这个原理，因为有一个进程正在对日志文件进行操作，所以其实rm操作并没有将文件真正的删除，所以磁盘空间并未释放。

三、问题解决

在了解了线上的问题现象以及以上的相关背景知识之后，我们就可以想到办法来解决这个问题了。

那就是想办法把SLS进程对这个日志文件的引用干掉，文件就可以真正的被删除，磁盘空间就能真正的被释放掉了。

kill -9 11526

$df

Filesystem 1K-blocks Used Available Use% Mounted on

/ 62914560 50331648 12582912 80% /

/dev/sda2 62914560 50331648 12582912 80% /home/admin

特别提醒下，在执行kill -9 之前，一定要考虑下执行的后果是什么，背后原理可以参考：我到服务器执行kill -9后，就被通知第二天别来了!

事后，我们经过复盘，发现之所以出现这样的问题，主要有两个原因：

线上日志打印太多，太频繁

SLS日志拉取速度太慢

深入分析后我们发现，这个应用打印了很多过程日志，最初日志打印是为了方便排查线上的问题，或者做数据分析用的，但是大促期间日志量激增，导致磁盘空间占用极速上升。

另外，因为该应用和几个其他的大应用共用了一份SLS的project，导致SLS拉取速度被拉低，进而导致进程一直无法结束。

事后，我们也总结了一些改进项，对于第二个问题，我们对于该应用的SLS配置做拆分，独立出来进行管理。

对于第一个问题，那就是大促期间引入日志降级的策略，一旦发生磁盘爆满，就是将日志降级掉。

关于日志降级，我开发了一个通用的工具，就是通过配置的方式，动态推送日志级别，动态修改线上的日志输出级别。并且把这份配置的修改配置到我们的预案平台上，大促期间进行定时或者紧急预案处理，即可避免这个问题。

下面和大家具体分享一下，日志降级工具的开发思路和相关代码：

1)日志级别

在开始正文前简单介绍下日志级别，不同的日志框架支持不同的日志级别，其中比较常见的就是Log4j和Logback。

在Log4j中支持8种日志级别，优先级从高到低依次为：OFF、FATAL、ERROR、WARN、INFO、DEBUG、TRACE、 ALL。

Logback中支持7种日志级别，优先级从高到低分别是：OFF、ERROR、WARN、INFO、DEBUG、TRACE、ALL。

可以看到常见的ERROR、WARN、INFO、DEBUG，这两者都是支持的。

所谓设置日志的输出级别表示的是输出的日志的最低级别，也就是说，如果我们把级别设置成INFO，那么包括INFO在内以及比INFO优先级高的级别的日志都可以输出。

无论是Log4j还是Logback，都是通过日志的配置文件来控制日志输出级别的。这里就不详述了。

2)日志框架

上面我们提到了Log4j和Logback，这两种都是比较常用的日志框架。

但是很多时候，我们在代码中打印日志并不是直接使用这种日志框架来进行的，而是依赖了一个日志门面来进行的，如slf4j、commons-logging等。

一般最最常用的方法就是通过slf4j提供的LoggerFactory的getLogger来获取Logger，然后进行日志打印

private static final Logger LOGGER = LoggerFactory.getLogger(LoggerService.class);

public void test(){

LOGGER.info("hollis log test");

}

当我们使用LoggerFactory.getLogger方法创建一个Logger对象的时候，会给他传入一个loggerName，通过这个loggerName来唯一识别一个Logger，如上面的方式就是使用LoggerService这个类的全路径名作为其loggerName。

loggerName是每一个Logger的配置信息一部分，除此之外还有日志输出级别等信息。

关于为什么不直接使用log4j和logback打印日志，我在《为什么阿里巴巴禁止工程师直接使用日志系统(Log4j、Logback)中的 API》中分析过。

3)Arthas改变日志级别

在开始介绍代码实现之前，先介绍一个工具，也可以帮助我们的动态修改日志级别。

那就是阿里开源的神器——Arthas (https://arthas.aliyun.com/doc/ )。

Arthas提供了一个logger命令，这个命令可以查看和更新logger信息，包括日志级别。

查看指定名字的logger信息

[arthas@2062]$ logger -n org.springframework.web

name org.springframework.web

class ch.qos.logback.classic.Logger

classLoader sun.misc.Launcher$AppClassLoader@2a139a55

classLoaderHash 2a139a55

level null

effectiveLevel INFO

additivity true

codeSource file:/Users/hengyunabc/.m2/repository/ch/qos/logback/logback-classic/1.2.3/logback-classic-1.2.3.jar

更新logger level

[arthas@2062]$ logger --name ROOT --level debug

update logger level success.

简单吧，使用一个命令就可以修改机日志级别了。

但是Arthas目前对于集群的支持并不是特别的友好，虽然他支持了通过Arthas Tunnel Server/Client 来远程管理/连接多个Agent，但是使用起来还不是很方便，并且对于命令的使用要求比较高。

还有就是我们系统通过一个工具，方便我们在大促期间通过预案方式动态调整日志级别，这方面使用arthas就不是很方便了。

4)代码实现

我写的这个工具功能很简单，就是提供动态修改日志级别的入口，方便用户动态修改级别。

并且为了方便使用，我将他封装在一个Spring Boot Starter里面了，还有就是将他直接对接到公司内部的配置中心中，可以方便的通过配置中心一键修改日志级别。

首先看下其中最核心的功能，那就是动态修改日志级别的部分，代码如下

import org.slf4j.Logger;

import org.slf4j.LoggerFactory;

import org.springframework.beans.factory.annotation.Autowired;

import org.springframework.boot.logging.LogLevel;

import org.springframework.boot.logging.LoggerConfiguration;

import org.springframework.boot.logging.LoggingSystem;

import java.util.Collections;

import java.util.List;

import java.util.Optional;

import java.util.stream.Collectors;

import static org.springframework.boot.logging.LoggingSystem.ROOT_LOGGER_NAME;

/**

* 日志级别设置服务类

*

* @author Hollis

*/

public class LoggerLevelSettingService {

@Autowired

private LoggingSystem loggingSystem;

private static final Logger LOGGER = LoggerFactory.getLogger(LoggerLevelSettingService.class);

public void setRootLoggerLevel(String level) {

LoggerConfiguration loggerConfiguration = loggingSystem.getLoggerConfiguration(ROOT_LOGGER_NAME);

if (loggerConfiguration == null) {

if (LOGGER.isErrorEnabled()) {

LOGGER.error("no loggerConfiguration with loggerName " + level);

}

return;

}

if (!supportLevels().contains(level)) {

if (LOGGER.isErrorEnabled()) {

LOGGER.error("current Level is not support : " + level);

}

return;

}

if (!loggerConfiguration.getEffectiveLevel().equals(LogLevel.valueOf(level))) {

if (LOGGER.isInfoEnabled()) {

LOGGER.info("setRootLoggerLevel success,old level is '" + loggerConfiguration.getEffectiveLevel()

+ "' , new level is '" + level + "'");

}

loggingSystem.setLogLevel(ROOT_LOGGER_NAME, LogLevel.valueOf(level));

}

}

private List  supportLevels() {

return loggingSystem.getSupportedLogLevels().stream().map(Enum::name).collect(Collectors.toList());

}

}

以上代码，就是根据用户传入的level的级别，将应用的ROOT日志输出级别修改掉。

这里面用到了一个关键的服务：

org.springframework.boot.logging.LoggingSystem

LoggingSystem服务是SpringBoot对日志系统的抽象，是一个顶层的抽象类。他有很多具体的实现

通过上图，我们可以发现目前SpringBoot目前支持4种类型的日志，分别是JDK内置的Log(JavaLoggingSystem)以及Log4j(Log4JLoggingSystem)、Log4j2(Log4J2LoggingSystem)以及Logback(LogbackLoggingSystem)。

LoggingSystem是个抽象类，内部有这几个方法：

beforeInitialize方法：日志系统初始化之前需要处理的事情。抽象方法，不同的日志架构进行不同的处理

initialize方法：初始化日志系统。默认不进行任何处理，需子类进行初始化工作

cleanUp方法：日志系统的清除工作。默认不进行任何处理，需子类进行清除工作

getShutdownHandler方法：返回一个Runnable用于当jvm退出的时候处理日志系统关闭后需要进行的操作，默认返回null，也就是什么都不做

setLogLevel方法：抽象方法，用于设置对应logger的级别

SpringBoot在启动时，会完成LoggingSystem的初始化，这部分代码是在LoggingApplicationListener中实现的

/**

* 执行LoggingSystem初始化的前置操作

*/

private void onApplicationStartingEvent(ApplicationStartingEvent event) {

//获取LoggingSystem的真实实现，

// 此处会根据不同的日志框架获取不同的实现，

// logback ：LogbackLoggingSystem

// log4j2：Log4J2LoggingSystem

// javalog：JavaLoggingSystem

this.loggingSystem = LoggingSystem

.get(event.getSpringApplication().getClassLoader());

//执行beforeInitialize方法完成初始化前置操作

this.loggingSystem.beforeInitialize();

}

有了LoggingSystem以后，我们就可以通过他来动态的修改日志级别。他帮我们屏蔽掉了底层的具体日志框架。

除了支持修改ROOT级别的日志以外，还可以支持用户自定义的日志的级别修改，代码实现如下：

先定义一个LoggerConfig，用来封装日志的配置

/**

* the config of logger

*

* @author Hollis

*/

public class LoggerConfig {

/**

* the name of the logger

*/

private String loggerName;

/**

* the log level

*

* @see LogLevel

*/

private String level;

public String getLoggerName() {

return loggerName;

}

public void setLoggerName(String loggerName) {

this.loggerName = loggerName;

}

public String getLevel() {

return level;

}

public void setLevel(String level) {

this.level = level;

}

}

接着提供方法动态修改日志级别：

public void setLoggerLevel(List  configList) {

Optional.ofNullable(configList).orElse(Collections.emptyList()).forEach(

config -> {

LoggerConfiguration loggerConfiguration = loggingSystem.getLoggerConfiguration(config.getLoggerName());

if (loggerConfiguration == null) {

if (LOGGER.isErrorEnabled()) {

LOGGER.error("no loggerConfiguration with loggerName " + config.getLoggerName());

}

return;

}

if (!supportLevels().contains(config.getLevel())) {

if (LOGGER.isErrorEnabled()) {

LOGGER.error("current Level is not support : " + config.getLevel());

}

return;

}

if (LOGGER.isInfoEnabled()) {

LOGGER.info("setLoggerLevel success for logger '" + config.getLoggerName() + "' ,old level is '"

+ loggerConfiguration.getEffectiveLevel()

+ "' , new level is '" + config.getLevel() + "'");

}

loggingSystem.setLogLevel(config.getLoggerName(), LogLevel.valueOf(config.getLevel()));

}

);

}

以上，根据用户传入的LoggerConfig，修改指定的loggerName对应的loggerLevel。至于LoggerLevel是怎么来的，就可以通过配置的方式传入，比如解析JSON格式的配置或者YML文件等。

如我们可以在配置中心中采用以下配置来控制日志级别，并推送:

[{'loggerName':'com.hollis.degradation.core.logger.LoggerLevelSettingService','level':'WARN'}]

以上配置，会使得loggerName为com.hollis.degradation.core.logger.LoggerLevelSettingService的日志的级别动态修改为WARN，另外，如果配置信息如下：

[{'loggerName':'com.hollis.degradation.core.logger','level':'WARN'}]

当然，这个配置也支持配置多个Logger的级别，如果是以下配置内容：

[

{'loggerName':'com.hollis.degradation.core.logger','level':'WARN'}

,{'loggerName':'com.hollis.degradation.core.logger.LoggerLevelSettingService','level':'INFO'}

]

加入代码中有多个日志，他们的定义方法分别为

private static final Logger LOGGER1 = LoggerFactory.getLogger(LoggerLevelSettingService.class);

private static final Logger LOGGER2 = LoggerFactory.getLogger(TestService.class);

private static final Logger LOGGER3 = LoggerFactory.getLogger(DebugService.class);

那么，配置生效后，会使得以上的LOGGER1的输出级别为INFO，而LOGGER2和LOGGER3的级别为WARN。

除此以外，上面的日志级别修改，可能会影响到我们自己这个工具本身的日志输出，所以，我们提供了一个方法，可以直接修改我们自己这个日志服务的日志级别

public void setDegradationLoggerLevel(String level) {

LoggerConfiguration loggerConfiguration = loggingSystem.getLoggerConfiguration(

this.getClass().getName());

if (loggerConfiguration == null) {

if (LOGGER.isWarnEnabled()) {

LOGGER.warn("no loggerConfiguration with loggerName " + level);

}

return;

}

if (!supportLevels().contains(level)) {

if (LOGGER.isErrorEnabled()) {

LOGGER.error("current Level is not support : " + level);

}

return;

}

if (!loggerConfiguration.getEffectiveLevel().equals(LogLevel.valueOf(level))) {

loggingSystem.setLogLevel(this.getClass().getName(), LogLevel.valueOf(level));

}

}

有了以上的LoggerLevelSettingService类以后，基本具备了动态修改日志的能力，接下来就是想办法通过配置中心动态修改日志级别了。

这里面因为不同的配置中心用法不同，我只是拿我们自己的配置中心简单举例

/**

* 降级开关注册器

*

* @author Hollis

*/

public class DegradationSwitchInitializer implements Listener, InitializingBean {

//从配置项中读取应用名，方便注册到配置中心

@Value("${project.name}")

private String appName;

@Autowired

private LoggerLevelSettingService loggerLevelSettingService;

//配置中心值发生变化会自动回调该方法

@Override

public void valueChange(String appName, String nameSpace, String name,

String value) {

if (name.equals(rootLogLevel.name())) {

loggerLevelSettingService.setRootLoggerLevel(value);

}

if (name.equals(logLevelConfig.name())) {

List  loggerConfigs = JSON.parseArray(value, LoggerConfig.class);

loggerLevelSettingService.setLoggerLevel(loggerConfigs);

}

//将降级工具的日志输出级别设置成INFO，保证其日志可以正常输出

loggerLevelSettingService.setDegradationLoggerLevel("INFO");

}

@Override

public void afterPropertiesSet() {

//将服务配置到配置中心

ConfigCenterManager.addListener(this);

ConfigCenterManager.init(appName, DegradationConfig.class);

}

}

以上，我们实现了监听配置中心的值的变化，动态修改日志级别。

基本功能就都完成了，接下来可以考虑如何让其他应用快速接入，那就是定义一个Starter，可以方便快速接入。主要代码如下：

先定义一个Configuration类：

/**

* @author Hollis

*/

@Configuration

@ConditionalOnProperty(prefix = "hollis.degradation", name = "enable", havingValue = "true")

public class HollisDegradationAutoConfiguration {

@Bean

@ConditionalOnMissingBean

@ConditionalOnProperty(name = "project.name")

public LoggerLevelSettingService loggerLevelSettingService() {

return new LoggerLevelSettingService();

}

@Bean

@ConditionalOnMissingBean

@ConditionalOnBean(value = LoggerLevelSettingService.class)

public DegradationSwitchInitializer degradationSwitchInitializer() {

return new DegradationSwitchInitializer();

}

}

在这个类里面定义两个bean，并且bean定义的前提是应用中配置了以下两个配置项：

hollis.degradation.enable = true

project.name = test

接下来就是定一个spring.factories文件，定义内容如下：

org.springframework.boot.autoconfigure.EnableAutoConfiguration=com.hollis.degradation.starter.autoconfiguration.HollisDegradationAutoConfiguration

以上，只需要在需要引入降级工具的应用中，引入我们的这个starter，并且配置两个配置项即可。

接入后，可以方便的在配置中心中动态修改单机或者集群的日志输出级别，并且可以在大促期间配置到预案平台上，通过紧急预案快速执行。

以上，基本实现了很多基本的功能，实现时考虑的因素主要有以下几个：

1、通用性。要同时可以支持不同的日志框架，客户端使用的日志框架不影响我们的功能，并且客户端不需要关心自己的日志框架的区别。

2、可配置性。可以将配置信息通过外部配置中心推送，可以快速进行调整。

3、易用性。通过封装到SpringBoot Starter中，方便客户端快速接入。

4、无侵入性。框架的使用不应该影响到应用的正常运行。

当然，这个工具只是我花了几个小时撸出来的，其中还有很多不足，其实还有很多事情可以优化，比如配置的格式可以支持多种、支持通过EndPoint查看日志配置情况等，这些都还没有实现。

本文只是提供一个思路，希望大家都能学会用工具化的方式解决日常工作中遇到的问题，学会造轮子。

四、思考

每次大促之后我们复盘，都会发现其实大多数问题都是由几个不起眼的小问题堆积到一起而引发的。

在问题分析过程中往往会需要运用到很多非开发技能相关的知识，如操作系统、计算机网络、数据库、甚至硬件相关的知识。

所以我一直认为，判断一个程序员是否牛X，就看他的解决问题的能力!