Log4j 结合钉钉打造日志机器人

在平常的开发中，找问题时，看日志经常是不可或缺的一件事件。对于错误日志，我们更是希望能够立马悉知，迅速对错误追本溯源，然后对错误进行修正。钉钉机器人的出现，无疑为我们第一时间对错误日志进行响应，提供了绝妙的工具。

自定义钉钉机器人

创建钉钉机器人

钉钉机器人只支持在群聊中创建，因而首先我们需要拥有一个群聊，然后在 “聊天设置” 中，找到 “智能群助手”，点击 “添加更多”，选择 “自定义”：

点击 “添加” 后，设置机器人名称（和头像），便完成了机器人的自定义，然后你会获得一个 webhook：

这个 webhook 是一个 URL，我们可以向这个 URL 发起 POST 请求，从而将我们的日志数据，发送给日志机器人，然后日志机器人产出消息提醒。钉钉支持多种消息类型，包括：text 类型、link 类型、markdown 类型等等，详细可见 钉钉开发平台。对于我们的日志消息来说，一般 text 类型就行。

Text 类型

text 类型的消息的格式如下：

{
    "msgtype": "text", 
    "text": {
        "content": "我就是我, 是不一样的烟火@156xxxx8827"
    }, 
    "at": {
        "atMobiles": [
            "156xxxx8827", 
            "189xxxx8325"
        ], 
        "isAtAll": false
    }
}

参数	参数类型	必须	说明
msgtype	String	是	消息类型，此时固定为：text
content	String	是	消息内容
atMobiles	Array	否	被@人的手机号
isAtAll	bool	否	@所有人时：true，否则为：false

使用 okHttp 发送消息

下面基于 okHttp 来演示如何发送 text 类型消息。首先我们定义消息的结构：

/**
 * 抽象消息类型（方便将来扩展其他类型的消息）
 */
public abstract class BaseMessage {

    private List<String> atMobiles;

    private boolean atAll;

    /**
     * 转为 JSON 格式的请求体
     *
     * @return 当前消息对应的请求体
     */
    public abstract String toRequestBody();

    public void addAtMobile(String atMobile) {
        if (atMobiles == null) {
            atMobiles = new ArrayList<>(1);
        }
        
        atMobiles.add(atMobile);
    }

    public void setAtAll(boolean atAll) {
        this.atAll = atAll;
    }

    public List<String> getAtMobiles() {
        return atMobiles != null ? atMobiles : Collections.emptyList();
    }

    public boolean isAtAll() {
        return atAll;
    }
}

/**
 * 文本消息
 */
public class TextMessage extends BaseMessage {

    /**
     * 消息内容
     */
    private final String content;

    public TextMessage(String content) {
        super();
        this.content = content;
    }

    @Override
    public String toRequestBody() {
        // 消息体
        JSONObject msgBody = new JSONObject(3);

        // 消息类型为 text
        msgBody.put("msgtype", "text");

        // 消息内容
        JSONObject text = new JSONObject(2);
        text.put("content", content);
        msgBody.put("text", text);

        // 要 at 的人的电话号码
        JSONObject at = new JSONObject(4);
        at.put("isAtAll", isAtAll());
        at.put("atMobiles", getAtMobiles());
        msgBody.put("at", at);

        return msgBody.toJSONString();
    }
}

然后定义消息发送工具，因为 HTTP 请求相对来说是个较为耗时的操作，所以我们基于 CompletableFuture 将 send 方法实现为异步发送：

/**
 * 钉钉机器人消息发送工具
 */
public class DingTalkTool {

    private static final Logger logger = LoggerFactory.getLogger(DingTalkTool.class);

    /**
     * OK 响应码
     */
    private static final int CODE_OK = 200;

    /**
     * OkHttpClient 可复用
     */
    private static final OkHttpClient HTTP_CLIENT = new OkHttpClient();

    /**
     * HTTP 媒体类型
     */
    private static final MediaType MEDIA_TYPE = MediaType.parse("application/json; charset=utf-8");
    
    /**
     * 修改为你的 webhook
     */
    private static final String WEBHOOK = "https://oapi.dingtalk.com/robot/send?access_token=your_access_token";

    /**
     * 异步发送消息
     *
     * @param message 消息
     */
    public static void send(BaseMessage message) {
        CompletableFuture.completedFuture(message)
                         .thenAcceptAsync(DingTalkTool::sendSync);
    }

    /**
     * 同步发送消息
     *
     * @param message 消息
     */
    private static void sendSync(BaseMessage message) {
        // HTTP 消息体（编码必须为 utf-8）
        RequestBody requestBody = RequestBody.create(MEDIA_TYPE, message.toRequestBody());

        // 创建 POST 请求
        Request request = new Request.Builder()
                .url(WEBHOOK)
                .post(requestBody)
                .build();

        // 通过 HTTP 客户端发送请求
        HTTP_CLIENT.newCall(request).enqueue(new Callback() {

            @Override
            public void onResponse(@Nonnull Call c, @Nonnull Response r) {
                int code = r.code();

                if (code != CODE_OK) {
                    logger.error("钉钉-发送消息失败，code={}", code);
                    return;
                }
                    
                // try-with-resource 自动关闭
                try (ResponseBody responseBody = r.body()) {
                    if (responseBody != null) {
                        // 注意是 responseBody.string，不是 responseBody.toString
                        JSONObject body = JSON.parseObject(responseBody.string());

                        int errCode = body.getIntValue("errcode");

                        if (errCode != 0) {
                            String errMsg = body.getString("errmsg");
                            logger.error("钉钉-发送消息出现错误，errCode={}, errMsg={}", errCode, errMsg);
                        }
                    }
                } catch (Exception e) {
                    logger.error("钉钉-处理响应消息异常", e);
                }
            }

            @Override
            public void onFailure(@Nonnull Call c, @Nonnull IOException e) {
                logger.error("钉钉-发送消息失败，请查看异常信息", e);
            }
        });
    }
}

OK，写个 Controller 来测试一下：

@RestController
public class SimpleController {

    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    @GetMapping("/divide/{a}/{b}")
    public int divide(@PathVariable int a, @PathVariable int b) {
        logger.info("SimpleController.divide start, a = {}, b = {}", a, b);

        try {
            return a / b;
        } catch (Exception ex) {
            String errMsg = String.format("SimpleController.divide error, a = %d, b = %d", a, b);
            // 日志记录错误信息
            logger.error(errMsg, ex);
            // 发送到钉钉群
            sendErrorMsg(errMsg, ex);
        }

        return Integer.MIN_VALUE;
    }

    private void sendErrorMsg(String errorMsg, Exception ex) {
        String stackTrace = ExceptionUtils.getStackTrace(ex);
        String content = errorMsg + LF + stackTrace;

        TextMessage message = new TextMessage(content);
        message.addAtMobile("要 at 的人的电话号码");
        
        DingTalkTool.send(message);
    }
}

访问一下 http://localhost:9090/divide/4/0，抛出异常，然后日志机器人发出提醒：

因为我设置了要 at 的人为我的号码，所以我被小机器人 at 了：

到这里，我们已经成功实现了通过钉钉来第一时间知道错误的日志信息。

结合 Log4j

Why

总觉得有什么地方还是不够好 —— 对的，感觉我们像是记录了两遍日志：使用 SLF4J （本文 SLF4J 的实现为 Log4j1.2）记录了一次，又使用 DingTalkTool 记录一次。程序员都是懒的，写重复代码对我们来说：

当然，我们可以封装一个如下的方式来解决问题，就是不怎么优雅：

public static void sendErrorMsg(Logger logger, String errorMsg, Exception ex) {
    String stackTrace = ExceptionUtils.getStackTrace(ex);
    String content = errorMsg + LF + stackTrace;

    logger.error(content);

    TextMessage message = new TextMessage(content);
    message.addAtMobile("要 at 的人的电话号码");

    DingTalkTool.send(message);
}

然后错误信息得这样来记录：

String errMsg = String.format("SimpleController.divide error, a = %d, b = %d", a, b);
// 记录并发送错误信息
sendErrorMsg(logger, errMsg, ex);

同时，因为我们要把错误级别的日志同时使用 SLF4J 和 DingTalkTool 记录，所以当日志中存在参数的时候，我们只能使用 String.format 来进行蹩脚的字符串格式化，而不能使用 SLF4J 的 {}。可是 使用 {} 不仅仅是因为好用，更因为 {} 处理起来是基于 String 的 indexOf 进行替换操作，效率远高于使用正则表达式的 String.format 方法。所以，必须安排！

How

我们知道 Log4j 提供了各种 Appender，下面 2 个最常用：

1. org.apache.log4j.ConsoleAppender（控制台）
2. org.apache.log4j.DailyRollingFileAppender（每天产生一个日志文件）

并且我们在配置 Log4j 时，可以提供多个 Appender，比如对于下面的配置文件：

<?xml version="1.0" encoding="UTF-8"?>
<!DOCTYPE log4j:configuration SYSTEM "http://toolkit.alibaba-inc.com/dtd/log4j/log4j.dtd">

<log4j:configuration>

    <!-- DEBUG 及以上级别的日志 输出到控制台 -->
    <appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">
        <param name="threshold" value="DEBUG"/>
        <param name="encoding" value="UTF-8"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%n%d %p %c{2} - %m%n"/>
        </layout>
    </appender>
    
    <!-- INFO 及以上级别的日志 按天输出到 logs/project.log -->
    <appender name="PROJECT_FILE" class="org.apache.log4j.DailyRollingFileAppender">
        <param name="threshold" value="INFO"/>
        <param name="file" value="logs/project.log"/>
        <param name="encoding" value="UTF-8"/>
        <param name="append" value="true"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%n%d %p %c{2} - %m%n"/>
        </layout>
    </appender>

    <!-- ERROR 及以上级别的日志 按天输出到 logs/error.log -->
    <appender name="ERROR_FILE" class="org.apache.log4j.DailyRollingFileAppender">
        <param name="file" value="logs/error.log"/>
        <param name="append" value="true"/>
        <param name="encoding" value="UTF-8"/>
        <param name="threshold" value="ERROR"/>
        <layout class="org.apache.log4j.PatternLayout">
            <param name="ConversionPattern" value="%n%d %p %c{2} - %m%n"/>
        </layout>
    </appender>
    
    <!-- 根 Logger -->
    <root>
        <level value="DEBUG"/>
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="PROJECT_FILE"/>
        <appender-ref ref="ERROR_FILE" />
    </root>

</log4j:configuration>

根 Logger 相当于创建了一个管道，然后管道上有三个 Appender。当使用 Logger 记录日志时，日志经过管道，然后根据自己的级别选择可以输出哪个 Appender（一个日志可以进入多个 Appender）。对于我们的配置，DEBUG 日志只会输出到 CONSOLE，INFO 及以上级别的日志会输出到 CONSOLE 和 PROJECT_FILE，ERROR 及以上级别的日志会输出到 CONSOLE、PROJECT_FILE 和 ERROR_FILE。

既然 Log4j 提供了 Appender 这样的管道机制，那么自然其也提供了可以自定义 Appender 的功能。所以我们可以实现一个输出到钉钉的 Appender，然后放到根 Logger 里面，并让其只输出 ERROR 及以上级别的日志到这个 Appender。通过实现 Log4j 已经提供的 AppenderSkeleton 抽象类，自定义的 Appender 只需要关心在 append 方法里面实现日志输出逻辑即可：

import static org.apache.commons.lang3.StringUtils.LF;

public class DingTalkAppender extends AppenderSkeleton {

    @Override
    protected void append(LoggingEvent event) {
        // 获得调用的位置信息
        LocationInfo loc = event.getLocationInformation();

        String className = loc.getClassName();

        // 如果是 DingTalkTool 的日志，不进行输出，否则网络出错时会引起无限递归
        // 如果只是想输出当前应用的日志，可以判断 className 是否以当前应用包名开头
        if (className.startsWith(DingTalkTool.class.getName())) {
            return;
        }

        StringBuilder content = new StringBuilder(8192);

        content.append("级别：").append(event.getLevel()).append(LF)
               .append("位置：").append(className).append('.').append(loc.getMethodName())
               .append("(行号=").append(loc.getLineNumber()).append(')').append(LF)
               .append("信息：").append(event.getMessage());

        Optional.of(event)
                .map(LoggingEvent::getThrowableInformation)
                .map(ThrowableInformation::getThrowable)
                .ifPresent(ex -> {
                    // 存在异常信息
                    String stackTrace = ExceptionUtils.getStackTrace(ex);
                    content.append(LF).append("异常：").append(stackTrace);
                });

        TextMessage message = new TextMessage(content.toString());
        DingTalkTool.send(message);
    }

    @Override
    public void close() { }

    @Override
    public boolean requiresLayout() { return false; }
}

然后在 Log4j 的配置文件中加入我们的 DingTalkAppender，设置为 Error 及以上级别的日志可输出到该 Appender：

<log4j:configuration>

    ......

    <appender name="ERROR_DINGTALK" class="xyz.mizhoux.logrobot.DingTalkAppender">
        <param name="threshold" value="ERROR"/>
    </appender>

    <!-- 根 Logger -->
    <root>
        <level value="DEBUG"/>
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="PROJECT_FILE"/>
        <appender-ref ref="ERROR_FILE" />
        <appender-ref ref="ERROR_DINGTALK"/>
    </root>

</log4j:configuration>

测试一下，首先修改 SimpleController：

@RestController
public class SimpleController {

    private final Logger logger = LoggerFactory.getLogger(this.getClass());

    @GetMapping("/divide/{a}/{b}")
    public int divide(@PathVariable int a, @PathVariable int b) {
        logger.info("SimpleController.divide start, a = {}, b = {}", a, b);

        try {
            return a / b;
        } catch (Exception ex) {
            logger.error("SimpleController.divide start, a = {}, b = {}", a, b, ex);
        }

        return Integer.MIN_VALUE;
    }
}

然后我们在浏览器中输入 localhost:9090/divide/2/0，日志机器人第一时间响应：

现在，我们再也不需要 sendErrorMsg 这样的方法，也不需要使用 String.format 这种难用且效率低的字符串格式化方法，记录错误信息的时候直接一个 logger.error 搞定~

本文的示例项目地址：log-robot