Stream 项目 - 分布式日志

发表于 | 分类于
本篇文章将介绍：方案选型、实现、与前台请求进行关联、自动打印 TID 与 requestId、log 日志同步 skywalking、忽略部分接口、skywalking 告警

学海无涯，心存高远。

方案选型

目前常见的分布式日志解决方案有很多。整个分布式日志需要解决的无非就是以下几点：

  • 日志收集
  • 日志存储
  • 调用链
  • 报警
  • 展示

最终选择方案：Grafana + SkyWalking + ElasticSearch + logback

实现

SkyWalking 集成

SkyWalking 最大的好处就是无侵入代码，但副作用就是有点耗内存。

  1. 到官网下载 SkyWalking。
  2. 修改 SkyWalking 配置文件，我这边使用的 ElasticSearch 来存储日志，所以还需要去部署 ElasticSearch。
  3. 将对应版本的探针放到业务服务器中。
  4. JVM 参数进行配置。 
    1
    		 
    -javaagent:/path/to/skywalking-agent.jar=[option1]=[value1],[option2]=[value2]

TID 暴露

使用 logback 打印日志，修改 logback.xml 的日志打印格式，将 TID 加入日志打印中。示例：

1
2
3
4
5
6
7
8
 
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
            <layout class="org.apache.skywalking.apm.toolkit.log.logback.v1.x.TraceIdPatternLogbackLayout">
                <!--格式化输出：%d表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度%msg：日志消息，%n是换行符-->
                <pattern>%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level logger_name:%logger{36} - [%tid] - message:%msg%n</pattern>
            </layout>
        </encoder>
    </appender>

与前台请求进行关联

前台发出一个请求，如何获取到 TID？上面我们已经将 TID 在日志中暴露出来了，下面要做的就是通过前台请求找到 TID。

添加 requestId

前台每次发起请求时在 header 中塞入一个 requestId 的 key，值只要是唯一的就行。这样每次请求就得到了一个类似 id 的东西（requestId）。

将 requestId 与 TID 关联

每次请求进来时，SkyWalking 都会生成一个唯一的 TID。只需要将 TID 和 requestId 都在日志中输出，这样就可以通过 requestId 获取到 TID 了。

新建一个拦截器，对 header 中的参数进行拦截，并把数据放入 MDC 中。示例：

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
 
public class MDCFilter implements Filter {
    @Override
    public void init(FilterConfig filterConfig) throws ServletException {

    }

    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
        this.insertIntoMDC(request);

        try {
            chain.doFilter(request, response);
        } finally {
            this.clearMDC();
        }

    }

    @Override
    public void destroy() {

    }

    void insertIntoMDC(ServletRequest request) {
        MDC.put("req.remoteHost", request.getRemoteHost());
        if(request instanceof HttpServletRequest) {
            HttpServletRequest httpServletRequest = (HttpServletRequest)request;
            MDC.put("req.requestURI", httpServletRequest.getRequestURI());
            StringBuffer requestURL = httpServletRequest.getRequestURL();
            if(requestURL != null) {
                MDC.put("req.requestURL", requestURL.toString());
            }

            MDC.put("req.requestId", httpServletRequest.getHeader("RequestId"));
            MDC.put("req.method", httpServletRequest.getMethod());
            MDC.put("req.queryString", httpServletRequest.getQueryString());
            MDC.put("req.userAgent", httpServletRequest.getHeader("User-Agent"));
            MDC.put("req.xForwardedFor", httpServletRequest.getHeader("X-Forwarded-For"));
        }

    }

    void clearMDC() {
        MDC.remove("req.remoteHost");
        MDC.remove("req.requestURI");
        MDC.remove("req.queryString");
        MDC.remove("req.requestURL");
        MDC.remove("req.method");
        MDC.remove("req.userAgent");
        MDC.remove("req.xForwardedFor");
        MDC.remove("req.requestNo");
        MDC.remove("req.ho  stIp");
    }


}

修改 logback.xml 的日志打印格式：

1
2
3
4
5
6
7
8
 
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
            <layout class="org.apache.skywalking.apm.toolkit.log.logback.v1.x.TraceIdPatternLogbackLayout">
                <!--格式化输出：%d表示日期，%thread表示线程名，%-5level：级别从左显示5个字符宽度%msg：日志消息，%n是换行符-->
                <pattern>%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level logger_name:%logger{36} - [%tid] - RequestId:%X{req.requestId} - message:%msg%n</pattern>
            </layout>
        </encoder>
    </appender>

自动打印 TID 与 requestId

最后我们需要每个请求过来时都打印一行基础日志，里面包含请求的方法名、TID、requestId。

编写一个 Before 切面，每次请求 controller 接口时打印日志，示例：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
 
@Aspect
@Component
@Log4j2
public class LogAspect {

    @Before("execution(* com.xxx.controller..*.*(..))")
    public void beforeLog(JoinPoint joinPoint){
        try{
            Signature signature = joinPoint.getSignature();
            log.info("...{}",signature.getName());
        }catch (Exception e){
            ...
        }
    }
}

log 日志同步 skywalking

skywalking 默认是不会记录程序中打印的日志的，如果需要将打印的日志同步到 skywalking 里面需要进行如下操作：

pom 文件引入：

1
2
3
4
5
 
<dependency>
    <groupId>org.apache.skywalking</groupId>
    <artifactId>apm-toolkit-logback-1.x</artifactId>
    <version>8.5.0</version>
</dependency>

logback 文件：

1
2
3
4
5
6
7
8
9
10
11
 
<appender name="skywalking-log" class="org.apache.skywalking.apm.toolkit.log.logback.v1.x.log.GRPCLogClientAppender">
    <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
        <layout class="org.apache.skywalking.apm.toolkit.log.logback.v1.x.mdc.TraceIdMDCPatternLogbackLayout">
            <pattern>%msg%n</pattern>
        </layout>
    </encoder>
</appender>

<root level="info">
    <appender-ref ref="skywalking-log"/>
</root>

修改 agent\config 配置文件：

1
2
3
4
 
plugin.toolkit.log.grpc.reporter.server_host=${SW_GRPC_LOG_SERVER_HOST:127.0.0.1}
plugin.toolkit.log.grpc.reporter.server_port=${SW_GRPC_LOG_SERVER_PORT:11800}
plugin.toolkit.log.grpc.reporter.max_message_size=${SW_GRPC_LOG_MAX_MESSAGE_SIZE:10485760}
plugin.toolkit.log.grpc.reporter.upstream_timeout=${SW_GRPC_LOG_GRPC_UPSTREAM_TIMEOUT:30}

忽略部分接口

项目里面使用了服务的健康监控，所以会有很多”/actuator/health”接口的请求。如果不过滤比较影响使用。

1、将 skywalking-apm/agent/optional-plugins 路径下的 apm-trace-ignore-plugin-8.6.0.jar 包拷贝到 skywalking-apm/agent/plugins 路径下。

2、在 skywalking-apm/agent/config 路径下新建名为 apm-trace-ignore-plugin.config 的配置文件。

3、修改 apm-trace-ignore-plugin.config 配置文件：

1
 
trace.ignore_path=${SW_AGENT_TRACE_IGNORE_PATH:/actuator/**,/eureka/**,Lettuce/**,Gson/**,Mysql/**}

skywalking 告警

skywalking 告警功能分两个部分：告警规则、网络勾子。

告警规则

SkyWalking 的 config/alarm-settings.yml 文件中预先定义了一些常用的告警规则。如下：

  • 过去3分钟内服务平均响应时间超过1秒
  • 服务成功率在过去2分钟内低于80%
  • 服务90%响应时间在过去3分钟内低于1000毫秒
  • 服务实例在过去2分钟内的平均响应时间超过1秒
  • 端点平均响应时间过去2分钟超过1秒

config/alarm-settings.yml 文件：

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
 
rules:
  # Rule unique name, must be ended with `_rule`.
  service_resp_time_rule:
    metrics-name: service_resp_time
    op: ">"
    threshold: 1000
    period: 10
    count: 3
    silence-period: 5
    message: Response time of service {name} is more than 1000ms in 3 minutes of last 10 minutes.
  service_sla_rule:
    # Metrics value need to be long, double or int
    metrics-name: service_sla
    op: "<"
    threshold: 8000
    # The length of time to evaluate the metrics
    period: 10
    # How many times after the metrics match the condition, will trigger alarm
    count: 2
    # How many times of checks, the alarm keeps silence after alarm triggered, default as same as period.
    silence-period: 3
    message: Successful rate of service {name} is lower than 80% in 2 minutes of last 10 minutes
  service_p90_sla_rule:
    # Metrics value need to be long, double or int
    metrics-name: service_p90
    op: ">"
    threshold: 1000
    period: 10
    count: 3
    silence-period: 5
    message: 90% response time of service {name} is more than 1000ms in 3 minutes of last 10 minutes
  service_instance_resp_time_rule:
    metrics-name: service_instance_resp_time
    op: ">"
    threshold: 1000
    period: 10
    count: 2
    silence-period: 5
    message: Response time of service instance {name} is more than 1000ms in 2 minutes of last 10 minutes

配置项目说明：

  • Rule name：规则名称，也是在告警信息中显示的唯一名称。必须以 _rule 结尾，前缀可自定义。
  • Metrics name：度量名称，取值为 oal 脚本中的度量名，目前只支持 long、double 和 int 类型。
  • Include names：该规则作用于哪些实体名称，比如服务名，终端名（可选，默认为全部）。
  • Exclude names：该规则作不用于哪些实体名称，比如服务名，终端名（可选，默认为空）。
  • Threshold：阈值
  • OP： 操作符，目前支持 >、<、=
  • Period：多久告警规则需要被核实一下。这是一个时间窗口，与后端部署环境时间相匹配
  • Count：在一个 Period 窗口中，如果 values 超过 Threshold 值（按 op），达到 Count 值，需要发送警报
  • Silence period：在时间N中触发报警后，在TN -> TN + period 这个阶段不告警。 默认情况下，它和 Period 一样，这意味着相同的告警（在同一个 Metrics name 拥有相同的 Id）在同一个 Period 内只会触发一次
  • message：告警消息

网络勾子

Webhook 可以简单理解为是一种 Web 层面的回调机制。SkyWalking 的告警消息会通过 HTTP 请求进行发送，请求方法为 POST，Content-Type 为 application/json。

参数说明：

  • scopeId、scope：所有可用的 Scope 详见 org.apache.skywalking.oap.server.core.source.DefaultScopeDefine
  • name：目标 Scope 的实体名称
  • id0：Scope 实体的 ID
  • id1：保留字段，目前暂未使用
  • ruleName：告警规则名称
  • alarmMessage：告警消息内容
  • startTime：告警时间，格式为时间戳

告警实现

定义一个实体类，用于接收 skywalking 传递过来的数据：

1
2
3
4
5
6
7
8
9
10
11
12
 
@Data
public class SkyWalkingAlarmDTO {

    private Integer scopeId;
    private String scope;
    private String name;
    private Integer id0;
    private Integer id1;
    private String ruleName;
    private String alarmMessage;
    private Long startTime;
}

定一个接口用于发送邮件：

1
2
3
4
5
6
7
8
9
10
 
@RestController
public class SkyWalkingAlarmController {
    @Autowired
    private EmailUtil emailUtil;
    
    @RequestMapping("/skywalking/send-email")
    public void sendEmail(@RequestBody List<SkyWalkingAlarmDTO> alarmList) {
        // 发送邮件
    }
}

修改 config/alarm-settings.yml 配置文件：

1
2
 
webhooks:
  - http://127.0.0.1:8080/skywalking/send-email