审计日志在分布式系统中的应用

前言

---

分布式系统的执行环境往往是异常复杂的，很多情况涉及到多节点间的消息通信。相比较于单节点系统而言，分布式系统在问题追踪，排查方面显然也复杂很多。那么这个时候，在分布式系统中，增加哪些类型的日志数据，来帮助我们发现和定位问题呢？答案就是我们今天将要阐述的审计日志（Audit log）。

审计日志的概念

---

很多人可能在想这样一个问题：同样是日志，审计日志和普通的日志，区别在于哪里呢？

审计日志，英文名为audit log，而audit这个单词的中文意思为“查账”，说明这些信息是具有准确记录的，并且会有规定的（账单）格式。也就是说，审计日志它会明确记录过往的“操作流水”，并且每天记录格式规则统一。这样能够方便地帮助我们分析这些日志。在分布式系统中，这些“操作流水”其实就是系统中每一次的操作行为。

下面笔者截取了HDFS的audit日志做为例子，如下：

2018-11-09 16:08:37,209 INFO FSNamesystem.audit: allowed=true ugi=hdfs (auth:SIMPLE) ip=xx.xx.xx.xx cmd=rename src=/tmp dst=/tmp2 perm=hdfs:hdfs:rw-r–r-- proto=rpc
2018-11-09 16:08:37,209 INFO FSNamesystem.audit: allowed=true ugi=hdfs (auth:SIMPLE) ip=/xx.xx.xx.xx cmd=open src=/data dst=null perm=null proto=rpc

我们可以看到，每天记录都准确地记下了每次操作行为的具体属性信息，因为日志格式非常规则化，我们完全可以将它们做文本处理分析，然后导入到SQL表里进一步进行查询分析。比如可以做“哪个时间段，哪部分操作占比最多”等等类似这样的查询。

审计日志功能类的编写

---

审计日志说到底它还是一种日志，只是经过人为的加工包装后再输出。所以对于审计日志工具类的开发来说，其实并不是特别难的。主要实现以下几点：

• 定义好消息的统一格式
• 构造出灵活的消息构建模式
• 复用Logger日志实例进行日志打印

第一点，消息格式的定义。这个决定了消息的最终输出内容，这个在开始时是一定要设想好的，哪些属性要必须输出的，哪些是可选的。下面是一个例子：

private static final String MSG_PATTERN =
“user=%s | ip=%s | op=%s %s | ret=%s”;

这里，我们用pattern模式的方法，要比直接字符串append方式组装灵活许多。
在上面的格式里，我们定义了4个属性值。

然后是对于日志消息的构造，这里强调的是灵活性，我们可以用构建者模式来做，示例代码如下：

首先AuditMessage消息对象如下：

/**
 * Defines audit message structure.
 */
public class AuditMessage implements Message {

  private String message;
  private Throwable throwable;

  private static final String MSG_PATTERN =
      "user=%s | ip=%s | op=%s %s | ret=%s";
  ...
}

  /**
   * Builder class for AuditMessage.
   */
  public static class Builder {
    private Throwable throwable;
    private String user;
    private String ip;
    private String op;
    private Map<String, String> params;
    private String ret;

    public Builder(){

    }

    public Builder setUser(String usr){
      this.user = usr;
      return this;
    }

    public Builder atIp(String ipAddr){
      this.ip = ipAddr;
      return this;
    }

    public Builder forOperation(String operation){
      this.op = operation;
      return this;
    }

    public Builder withParams(Map<String, String> args){
      this.params = args;
      return this;
    }

    public Builder withResult(String result){
      this.ret = result;
      return this;
    }

    public Builder withException(Throwable ex){
      this.throwable = ex;
      return this;
    }

    public AuditMessage build(){
      AuditMessage auditMessage = new AuditMessage();
      // 用format方法构建完整消息
      auditMessage.message = String.format(MSG_PATTERN,
          this.user, this.ip, this.op, this.params, this.ret);
      auditMessage.throwable = this.throwable;
      return auditMessage;
    }
  }

然后在定义日志输出类，来输出这个message对象实例：

/**
 * Class to define Audit Logger for Ozone.
 */
public class AuditLogger {

  ...
  
  /**
   * Initializes the logger with specific type.
   * @param loggerType specified one of the values from enum AuditLoggerType.
   */
  private void initializeLogger(AuditLoggerType loggerType){
    this.logger = LogManager.getContext(false).getLogger(loggerType.getType());
  }


  public void logWriteSuccess(AuditMessage msg) {
    this.logger.logIfEnabled(FQCN, Level.INFO, WRITE_MARKER, msg, null);
  }

  public void logWriteFailure(AuditMessage msg) {
    this.logger.logIfEnabled(FQCN, Level.ERROR, WRITE_MARKER, msg,
        msg.getThrowable());
  }

审计日志在实际系统中的应用

---

下面我们对照上面写的类，来看看它是如何被应用到系统中的，下面的例子也是大多数分布式系统常用的audit log的打印手法。

第一步，初始化得到audit日志打印实例：

  private static final AuditLogger AUDIT = new AuditLogger(AuditLoggerType.OMLOGGER);

在服务管理对象的关键操作行为处（RPC调用处），加上操作日志是，

  @Override
  public OmKeyLocationInfo allocateBlock(OmKeyArgs args, long clientID)
      throws IOException {
    boolean auditSuccess = true;
    Map<String, String> auditMap = (args == null) ? new LinkedHashMap<>() :
        args.toAuditMap();
    auditMap.put(OzoneConsts.CLIENT_ID, String.valueOf(clientID));
    try {
      metrics.incNumBlockAllocateCalls();
      return keyManager.allocateBlock(args, clientID);
    } catch (Exception ex) {
      metrics.incNumBlockAllocateCallFails();
      auditSuccess = false;
      AUDIT.logWriteFailure(buildAuditMessageForFailure(OMAction.ALLOCATE_BLOCK,
          auditMap, ex));
      throw ex;
    } finally {
      if(auditSuccess){
        AUDIT.logWriteSuccess(buildAuditMessageForSuccess(
            OMAction.ALLOCATE_BLOCK, auditMap));
      }
    }
  }
  ...
    public AuditMessage buildAuditMessageForFailure(AuditAction op,
      Map<String, String> auditMap, Throwable throwable) {
    return new AuditMessage.Builder()
        .setUser((Server.getRemoteUser() == null) ? null :
            Server.getRemoteUser().getUserName())
        .atIp((Server.getRemoteIp() == null) ? null :
            Server.getRemoteIp().getHostAddress())
        .forOperation(op.getAction())
        .withParams(auditMap)
        .withResult(AuditEventStatus.FAILURE.toString())
        .withException(throwable)
        .build();
  }

我们看到，在上面的失败和成功的地方都打印了audit日志，但是如果我们不考虑失败的情况，只需代码块的最后finally块区域，添加日志即可。这样可以确保无论前面逻辑执行如何，能够保证操作记录不被丢失。

OK，以上就是今天阐述的一个小的知识点，不是很复杂，但用处不小。