集中式日志管理部署下的Log输出

集中式日志管理部署下的Log输出

Log是程序记录执行过程,辅助排查问题的必备良药。随着后台程序越来越复杂,集群规模越来越大,通常会引入集中式程序日志管理,比如使用splunk或者ELK统一管理日志。Log打的好,排错无烦恼,但是往往打不好。下面就聊聊怎么打Log,特别是在使用集中式日志管理架构时。


为什么Log输出变得越来越难

一句话描述Log查找的需求:根据查询条件,返回并且仅返回所关注的用例相关的所有上下文。

怎么变难的:

  • 单线程同步:有时间戳和重要参数值就差不多了
  • 多线程同步:你可能需要线程号(线程名)
  • 单线程异步:比如Node.js,这个今天不聊
  • 多线程异步:比如.Net异步编程,线程号没法用了,但是可以用AsyncLocal替代线程号
  • 单机器多进程:好像也还好,登到机器上分别看也行
  • 多机器多进程:完蛋,看个日志还得连到不同机器,就算同步日志文件到统一的文件服务器,也是太多
  • 成百上千台服务器,复杂的服务调用:更完蛋,根本都没有权限登到服务器上去,这个时候引入了集中式日志管理

对于单个进程,打Log需要考虑的问题会简单一些。集中式日志管理部署对Log查找带来新的问题:

  • 不同机器、进程、线程输出的Log丢到数据库里,需要有字段区分
  • 不同服务、组件之间有调用,需要有字段关联
  • Log的大小、跨行、格式解析带来各种古怪的问题

打Log要考虑的可能有:

  • Log不能太多
  • Log要使用合适的级别
  • Log输出要尽可能快
  • Log应包含哪些信息
  • Log落盘之后会被转送到别处,这中间的坑要绕过去

我们现在是怎么打Log的

会有一些代码示例,这里用的是Java

日志级别

  • INFO还是DEBUG

    • 在生产环境DEBUG级别可能不会输出,所以尽可能用INFO,除非会导致日志过多性能下降(比如在一个用例的执行过程中会打印很多次的)
  • ERROR还是WARN
    • 尽量不要用,如果一个错误程序可以处理,可能用WARN更合适,这样可以通过搜索ERROR找到你需要改代码的错误
  • FATAL级别怎么用
    • FATAL或者CRITICAL可以理解为特别严重的错误,自然要谨慎对待,通常是需要运维快速介入的错误才需要用到这个级别
    • slf4j Logger接口没有fatal()方法,不过这没关系,就算有,也不建议使用。因为很有可能业务数据就包含FATAL、CRITICAL字符串,如果你直接用,然后通过这两个字符串设置告警,就会有误报
    • 所以应该定义产品自己的FATAL级日志的TAG,比如 XYZ_OP_CRITICAL ,然后可以这么打Log:
    ERROR 2015-09-08 18:46:19,333[main] App.java (line 37) we use XYZ_OP_CRITICAL as FATAL Tag,
      XYZ_MODULE_ABC start failure due to connect DB failure.
  • 哪些错误可以使用FATAL级别
    • 程序启动失败
    • 程序遇到了不可恢复的错误
    • ...

日志输出性能

  • 尽量不要使用字符串格式化,特别是DEBUG级别的Log,直接把参数丢给Log库,这样可以节省字符格式化的计算开销

    • 有些文章建议输出DEBUG级别Log之前判断一下是否Enable DEBUG级别,其实大多数时候没必要,因为Log库其实已经做了对应的优化
  • 如果日志量可能很大,也许你需要考虑使用异步模式输出日志文件
  • 日志输出格式也会影响输出性能,在下文会有说明

日志内容

程序启动日志
  • 应该要输出启动日志
  • 包含程序版本信息,最好还有编译时间
  • 包含配置信息,但不包括敏感信息,比如数据库密码之类
性能日志
  • 批量接口

    • 可以包含批量大小、成功数、失败数、成功占比
  • 耗时事务操作
    • 可以在事务结束时打印一行包括整个事务各个步骤的耗时
  • 计数器类日志
    • 可以通过单独的性能收集器实现
  • 慢请求处理
    • 请求延迟对于衡量服务质量非常重要,最好设置一个阈值,比如超过2秒的POST请求处理,超过100ms的GET请求处理单独记录,通常可以用拦截器实现
    • 有时候请求处理耗时会超过客户端设定的Timeout,这个时候服务端就算处理成功了,客户端仍然认为是处理失败了,可能会重试。服务端程序最好支持客户端提供Timeout参数设置,这样在操作执行完时,可以决定回滚事务或者至少打印错误日志。
其它Log里需要输出的常用信息
  • 调用端的IP端口
  • 请求URL
  • 线程名
  • 源代码文件名和行号
  • TraceID
  • RequestID
  • TenantID (对于多租户服务端)
  • 用户ID
  • 时间ID
  • 异常栈 StackTrace(特别是对于未知异常)
七层负载均衡器

当你的Web服务部署在七层负载均衡服务器后面时,没有办法直接获取到客户端的IP端口信息,你可能需要从HTTP head里取值。

  • 获取Client IP代码示例
public static String getClientIpAddr(HttpServletRequest request) {
  String ip = request.getHeader("x-forwarded-for");
  if (ip == null || ip.length() == 0 || "unknown".equalsIgnoreCase(ip)) {
    ip = request.getHeader("Proxy-Client-IP");
  }
  if (ip == null || ip.length() == 0 || "unknown".equalsIgnoreCase(ip)) {
    ip = request.getHeader("WL-Proxy-Client-IP");
  }
  if (ip == null || ip.length() == 0 || "unknown".equalsIgnoreCase(ip)) {
    ip = request.getRemoteAddr() + ":" + request.getRemotePort();
  }
  return ip;
}

日志输出格式

以 log4j 配置为例

  • 一个典型的log4j.properties
# log4j configuration files
log4j.rootLogger=INFO, R

# rolling log file
log4j.appender.R=org.apache.log4j.RollingFileAppender
log4j.appender.R.encoding=UTF-8
log4j.appender.R.maxFileSize=20MB
log4j.appender.R.maxBackupIndex=50
log4j.appender.R.layout=org.apache.log4j.PatternLayout
log4j.appender.R.File=/var/log/test/test.log

# use %c to get better performance than %F
# log4j.appender.R.layout.ConversionPattern=%5p %d{ISO8601} [%t] %c %m%n
log4j.appender.R.layout.ConversionPattern=%5p %d{ISO8601} [%t] %F (line %L) %m%n

注意PatternLayoutConversionPattern配置,和性能相关。如果输出内容包含调用位置信息(%F文件名, %M方法名, %L代码行),性能会下降很多(大概是5~10倍差别)。如果发现日志会影响程序性能,就需要避免输出调用位置信息,其实用类名%c替代文件名%F大部分时候已经够用了。

使用键值对输出的风格

上面的ConversionPattern配置影响的是代码行输出Log内容相关元数据,按照最普通的方式输出,如果需要把Log的一行内容解析到不同字段,可以使用正则匹配抽取。如果对抽取过程的性能有较高要求,还可以使用每个字段固定宽度的方式输出,这样可以按照字节长度截取得到不同字段的信息。

不足之处在于,对于自定义字段,没有办法很方便的抽取。这里推荐一种键值对输出风格,特别适合对Log内容进行预处理,解析到不同的字段,输出样例如下:

INFO 2017-11-24T07:08:54,609 [pool-5-thread-1] [ExecutorManager] tryCount=50, consumeCount=3, consumeTimeMillis=1235

元数据可以通过正则匹配,自定义内容可以通过kv提取函数匹配,解析到不同字段的值样例如下:

{
  "log_level" : "INFO",
  "log_timestamp" : "2017-11-24T07:08:54,609",
  "log_thread" : "pool-5-thread-1",
  "log_class" : "ExecutorManager",
  "log_message" : "tryCount=50, consumeCount=3, consumeTimeMillis=1235",
  "tryCount" : 50,
  "consumeCount" : 3,
  "consumeTimeMillis" : 1235
}
使用Json输出Log元数据

可以直接使用PatternLayout,一个比较取巧的方式,只需要保证%m的内容是一个普通字符串就可以了。

log4j.appender.stdout=org.apache.log4j.ConsoleAppender
log4j.appender.stdout.encoding=UTF-8
log4j.appender.stdout.layout=org.apache.log4j.PatternLayout
log4j.appender.stdout.layout.ConversionPattern
  ={"debug_level":"%p","debug_timestamp":"%d{ISO8601}",
    "debug_thread":"%t","debug_class":"%c","debug_message":"%m"}%n

特殊日志的处理

一行Log超级长

太长的Log可能会在传输过程中被截断,比如Logstash默认只保留一行Log的前8013个字节。所以:

  • 尽可能避免一行输出太长的Log,输出越多丢失的信息越多
  • 如果一定要记录超大的一行记录,可以考虑拆分成多行输出
Exception StackTrace

因为集中式日志管理按照行为单位来存储日志,但是用error()方法打印Exception的时候只有第一行包含 Log元数据(机器信息、时间戳、线程名之类)。所以可能需要特殊处理,比如:

public static void errorStackTrace(Logger logger, Exception e) {
  StackTraceElement[] stackTrace = e.getStackTrace();
  for (StackTraceElement stackTraceElement : stackTrace) {
    logger.error("\t at {}", stackTraceElement.toString());
  }
}

注意上面制表符之后还跟了个空格,因为有时候日之库会直接存\t,和后面的内容黏连在一起

Json转义字符

Json本身支持转义字符,有时候我们一些Class的field本省存储的就是一个Json String,这个时候再输出,完蛋,好多个斜杠,就像这样\\\\\n之类的。日志库可能处理的不太好,尽量避免这种用法。

一些小技巧

如何确定我的线程还活着

对于一些常驻线程,可能包含对某个方法的高频调用,每次都打Log的话量太多。可以写个HeartbeatLogger类,支持设定心跳间隔,比如每隔5分钟才打印一次。 我们是这么用的:

HeartbeatLogger heartbeatLogger = HeartbeatLoggerBuilder
    .aHeartbeatLogger()
    .withClassName(this.getClass().getSimpleName())
    .withIntervalSeconds(heartbeatIntervalSeconds)
    .withCustomerKeyValue("methodName", "checkMethodA")
    .build();
while(shouldKeepRunning) {
    heartbeatLogger.hearbeat();
}
在分布式流处理平台上,如何打印主机名和进程号

可以使用 MDC(Mapped Diagnostic Context),在log4j里使用 %X引用设置的变量。

  • Java Code
MDC.put("PID", pid);
MDC.put("HOSTNAME", hostName);
  • log4j.properties ConversionPattern
%5p %d{ISO8601} [%X{HOSTNAME}] [%X{PID}] [%t] %c %m%n

参考资料

时间: 2024-10-31 21:26:26

集中式日志管理部署下的Log输出的相关文章

用ELK打造可视化集中式日志

Elk是Elastic search, Logstash和Kibana三者的简称. Elastic search顾名思义是致力于搜索,它是一个弹性搜索的技术平台,与其相似的有Solr,二者的对比可参考下面这篇文章: Elastic search与Solr选型 总结一下就是,如果你不喜欢夜店咖还是喜欢忠实可靠的老婆,那选Elastic search准没错,何况他还有那么一点美.目前运用ES的案例也不少了,比如it屌丝们都爱的Git hub以及我D痛恨的Wiki. Logstash,也可以顾名思义一

《实施Cisco统一通信管理器(CIPT1)》——2.3 使用集中式呼叫处理的多站点WAN部署模型

2.3 使用集中式呼叫处理的多站点WAN部署模型 实施Cisco统一通信管理器(CIPT1)使用集中式呼叫处理的多站点WAN部署模型由一个CUCM集群组成,它可以为多个站点提供服务,并通过IP WAN来传输多个站点之间的IP电话通讯流量. IP WAN也负责承载位于中心站点的CUCM集群,与位于远端站点的电话之间的呼叫控制信令. 图2-2是一个典型的集中式呼叫处理部署案例,管理员在中心站点部署了一个CUCM集群,并通过启用了QoS的IP WAN链路将所有站点连接起来.远端站点需要依靠集中式CUC

《实施Cisco统一通信管理器(CIPT1)》一2.3 使用集中式呼叫处理的多站点WAN部署模型

2.3 使用集中式呼叫处理的多站点WAN部署模型 实施Cisco统一通信管理器(CIPT1)使用集中式呼叫处理的多站点WAN部署模型由一个CUCM集群组成,它可以为多个站点提供服务,并通过IP WAN来传输多个站点之间的IP电话通讯流量. IP WAN也负责承载位于中心站点的CUCM集群,与位于远端站点的电话之间的呼叫控制信令. 图2-2是一个典型的集中式呼叫处理部署案例,管理员在中心站点部署了一个CUCM集群,并通过启用了QoS的IP WAN链路将所有站点连接起来.远端站点需要依靠集中式CUC

.Net下几种日志管理方法

.Net下几种日志管理方法 日志是应用程序中不可缺少的一部份,不仅可以记录应用程序的运行状态,还可以记录一些BUG,便于应用程序的更新与修改.在.Net有好几种方法可以对日志进行管理.1.数据库日志.2.文本日志.3.系统事件日志. 首先,对于数据库日志而言,它的使用简单而且方便.这里就不做太多的讨论,相信写过与数据相关的项目的人都会用数据来记录一些日志.然而它唯一不好的就是:必须先保证你的数据库链接是正确无误的.然而这一保证不是必然的,所以这里我再讨论一下其它的两种情况,文本日志及系统事件日志

HDFS集中式的缓存管理原理与代码剖析

Hadoop 2.3.0已经发布了,其中最大的亮点就是集中式的缓存管理(HDFS centralized cache management).这个功能对于提升Hadoop系统和上层应用的执 行效率与实时性有很大帮助,本文从原理.架构和代码剖析三个角度来探讨这一 功能. 主要解决了哪些问题 用户可以根据自己的逻辑指定一些经常被使用的数据或者高优先级任务对应的 数据,让他们常驻内存而不被淘汰到磁盘.例如在Hive或Impala构建的数据仓库 应用中fact表会频繁地与其他表做JOIN,显然应该让fa

视角 | 多容器环境下的日志管理难?有人做起了这个生意

本文讲的是视角 | 多容器环境下的日志管理难?有人做起了这个生意,[编者的话]本文介绍了一个新的工具SPM,它用于解决在多容器环境下日志管理所遇到的问题,同时它整合了多种功能,避免了以往需要安装多种工具的麻烦,配合Kibana的展示功能,使得该工具还是值得一试的. 在微服务流行的今天,日志路由和解析的传统静态配置方法已经有点吃力:事实上,它还带来了额外的复杂度和资源消耗.相对的,这使得不能运行在单机上的微服务的数量降低了. 在SPM for Docker整合的日志管理功能中,对微服务进行了支持,

日志-怎么控制,不让linux下debug信息输出到Tomcat下log/catalina.out

问题描述 怎么控制,不让linux下debug信息输出到Tomcat下log/catalina.out 最近维护服务器的时候,发现上传上去的文件大小全部为0, 一查才知道磁盘已经被占满了,排查下来发现tomcat下log/catalina.out文件 竟然达到惊人的10G,观察里面的信息,几乎全部是项目的debug信息, 而项目log4j的配置输出地址日志信息正常,等于是日志信息正常打印到指定位置之后, 又重复打印到catalina.out. 搜了下这个问题,几乎全是如何分割或清空catalin

福建省促进大数据发展:变分散式管理为统筹集中式管理

构建"一人一档.一组一档.一物一档.一事一档"大数据平台,变分散式管理为统筹集中式管理-- 汇聚共享,让政府数据"增值" 东南网8月2日讯(福建日报记者 谢贤伟) 要是有这样一个平台,能汇集政府各部门各行业的运行数据和来自互联网的相关数据,建立经济运行预测模型,那么,实时掌握经济运行形势.预测经济发展趋势.预警经济运行潜在风险,就会更准确高效.这一切,依靠大数据,便可实现.福建,正向着大数据发力. 日前,省政府正式出台<福建省促进大数据发展实施方案(2016-

Hadoop2.6(NN/RM)高可用集群安装与部署

 Hadoop2对HDFS的改进很大,支持HDFS(NameNode) 和ResourceManager高可用性,避免集群中单点故障造成整个集群不可用.那么,从本文开始将部署一套高可用Hadoop集群及家族中相关开源系统,具体根据下面规划来,本文只部署高可用Hadoop集群,后续很快更新其他软件部署及使用. 一.部署前准备 操作系统:CentOS7_x64 安装目录:/opt 1. 节点分配 HostName IP Hadoop HBase Zookeeper Hive HMaster0 192