nginx/tomcat日志格式规范

    最近准备设计和开发一套日志收集平台，进而后续进行实时的日志分析、业务监控和预警等。在此之前，需要制定日志的格式规范，当然还有其他的约束性规范，才能良好的实现日志搜集、数据分拣、数据分析等特性。

 

    制定日志格式规范的方式与目的：

    1）所有项目，日志格式统一，可以极大的简化日志收集和分析的复杂度。

    2）nginx、tomcat等日志格式，需要合理，让日志查看和问题排查更加便捷，排除不用的字段信息，增加更多的有效字段。

    3）考虑到日志格式将来总会要变化，但是日志数据会被运维、开发、大数据平台、BI、安全等团队共同使用，为了避免日志格式的变化给所有相关团队带来干扰，降低改动的影响面，我们将日志中的字段进行分“域”；每个域包括多个字段，不同的团队关注不同的域，某个域中的字段列表改动时，不影响其他团队对数据的使用。我们解析日志数据时，首先将日志按照域分隔符分成多个"域"，然后根据字段在域中的相对位置来获取字段值，而不是使用字段在整条日志的位置。我们使用“^_^”符号作为域分隔符。

    4）为了便于数据分拣、日志收集，我们约定所有的日志文件名必须遵循统一规则，这对Flume进行数据搜集非常有利。比如nginx日志、tomcat access log、业务日志等，日志的文件名遵循：<project-name>.<tag>.log.<yyyy-MM-dd>.<index>；例如：order-center.error.log.2017-10-11.0，其中<index>为rolling时生成的索引号。统一日志名称的原因是：易于通过文件名了解日志的来源和核心特性，此外对于Flume而言可以从文件名中得知项目的名称、日志等重要信息，既可以在收集时对日志进行按项目、日志进行分类存储。

    5）严格控制日志文件的大小，适时对日志文件进行rolling，我们约定任何日志文件的大小不得超过256M，超过此值时应该对日志进行rolling。原因非常简单，较大的日志文件既不便于收集、传输，也不便于进行查看，此外较大的日志还会降低文件IO的效率。在此基础上，我们要求在打印日志时需要对日志信息进行合理规划，尽可能精简日志信息，冗杂而庞大的日志信息不仅价值较低，而且消耗存储，此外较大的日志内容输出还会增加宿主机器的IO负载，毕竟我们的普通的application机器的IOPS通常不高。

    6）为了便于日志分拣、日志内容的可读性、本地性，我们在nginx、tomcat等所有日志内容中，都打印“当前机器的IP”、“日志产生的时间戳”等标记信息。

 

1、nginx日志格式：

log_format  main  '$time_local|$hostname|$remote_addr|$upstream_addr|$request_time|$upstream_response_time|$upstream_connect_time|'

'$status|$upstream_status|-|$bytes_sent|-|-|$remote_user|$request|$http_user_agent|$http_referer|^_^|'

'$scheme|$request_method|$request_trace_id|$request_trace_seq|^_^|'

'$http_x_forwarded_for|$http_Authorization|$cookie_uid';

 

    其中有几个“-”占位符，本人使用nginx 1.10版本，但是有几个非常重要的字段需要等到1.11版本发布后才能使用，所以此处先用“-”占位。

    nginx日志格式，本人参考了AWS ELB，我觉得ELB的日志格式还是比较规范，具有较高的参考价值。此处的nginx格式，与ELB日志格式在字段含以上一一对应，对于nginx缺失的字段，先用“-”占位。

   我们将nginx日志分为四个域，第一个域包含一些最常用、最重要的字段，通常与性能评估、数据分拣有关系；第二个域表示此次请求的一些状态信息，排查问题时可以关注此域；第三个域，是关于请求追踪的，我们为每个请求设定request_id等（其中$request_trace_id，$request_trace_seq是自定义的变量），此后在业务监控时可以将异常请求的全追踪链整理出来；第四个域，面向开发，通常用于打印一些HTTP参数等。

    $request_trace_id和$request_trace_seq是自定义的变量，分别表示“请求的追踪ID”和“请求追踪的序列数字”：

    一个新的请求都会有一个唯一的trace_id，此trace_id通常有最顶层proxy负责生成，生成后将会把trace_id添加到header中并传递给upstream层（tomcat等），upstream应用中如果有请求扇出，则继续将此trace_id下发，最终实现请求的链路追踪，我们将链路的追踪信息收集并整理，后期用于评估接口性能、业务监控、流量异常发现、容量规划等。

    如果proxy层发现请求的header中已经包含trace_id，那么我们认为此请求是“链路的一个环节”而不是一个新的请求，此时保留trace_id，并添加到header中继续转发。request_trace_seq默认为0，有upstream负责进行维护seq的值，比如每次下发对其值进行自增，nginx不负责此值的自增的原因是希望有应用程序自己决定seq的顺序。

##trace.setting
set	$request_trace_id $http_x_request_id;
set $request_trace_seq $http_x_request_req;

if ( $request_trace_id = '' ) {
	set	$request_trace_id $pid-$connection-$bytes_sent-$msec;
}
if ( $request_trace_seq = '' ) {
   set	$request_trace_seq 0;
}

 

....
server {
    listen       80;
    server_name  demo.com;
    include trace.setting;
    access_log  /var/log/nginx/demo.log  main;
    proxy_send_timeout      1800s;
    proxy_read_timeout      1800s;    

    location / {
            proxy_pass         http://10.0.0.1:8080;
            proxy_set_header   Host             $host;
            proxy_set_header   X-Request-ID $request_trace_id;
            proxy_set_header   X-Request-Seq $request_trace_seq;
    }
}
....

 

    字段含义（逐一对应）：

字段名                          解释
time_local                   日志时间
hostname                 当前机器的hostname（非IP）
remote_addr                  客户端地址
upstream_addr               后端Server的地址
request_time            nginx处理请求的时长，从获取Client请求的首个字节开始到响应数据发送完毕，单位为“秒 + 毫秒”
upstream_response_time      从nginx与upstream建立连接开始到response数据接收完毕。
upstream_connect_time     与upstream建立连接的时间。
status                  nginx响应状态码
upstream_status        upstream返回给nginx的状态码（tomcat或者后继nginx）
bytes_received         nginx接收到Client的请求数据大小，1.11版本才能支持，此处用“-”占位符替代
bytes_sent               nginx返回给Client的数据大小
upstream_bytes_sent      nginx发送给upstream的字节数，1.11版本才支持，此处使用“-”占位符替代
upstream_bytes_received   nginx接收到upstream响应的字节数，1.11版本才支持，此处使用“-”占位符替代
remote_user            基本认证中的user信息
request                   HTTP请求行—首行
http_user_agent         标头中“User-Agent”值
http_referer              标头中“Referer”值
scheme                  请求的Scheme，HTTP或者HTTPS
request_method            HTTP(S)请求的方法名：GET,POST等
request_trace_id        获取标头中“X-Request-ID”值，如果不包含此header，则创建新的Trace_id。
request_trace_seq       获取标头中“X-Request-Seq”值，如果存在，表明此请求是trace link下发的请求。此值用于追踪请求链的层级或者顺序
http_{key}           获取HEADER中指定key的值。
cookie_{key}          获取COOKIE中指定key的值。

 

 2、Tomcat Access log格式规范

    对于JAVA WEB项目，tomcat提供了内置的access日志机制，有点类似于nginx的access日志；在开启时，tomcat会把接收到的请求信息打印在日志中，这对我们分析数据、排查问题、性能检测等有很大帮助。只需要修改server.xml文件即可：

<Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs"

               prefix="access.log" suffix="" renameOnRotate="true"

pattern="%{yyyy-MM-dd HH:mm:ss}t|%A|%a|%p|%m|%s|%D|

%b|%{begin:msec}t|%{end:msec}t|^_^|

%{X-Request-ID}i|%{X-Request-Seq}i|^_^|

%S|%r|%{Referer}i|%{User-Agent}i" />

 

    基本原则跟nginx一样，分域，第一个域仍然是关于数据分拣、性能检测相关；第二个域是关于请求追踪的，将来对接追踪链系统；第三个域，是开发关注的，通常是打印一些HTTP 参数等。不过比较遗憾的是，tomcat access日志所能提供的字段信息比较少，没有nginx那么丰富。

    此外，为了让access log的文件名称遵循规范要求，我们在prefix和suffix的配置上做了调整。

    为了达成请求追踪的目的，我们在tomcat access log中也打印了request_trace_id和seq的相关信息。

 

3、业务日志格式

    我们的java程序内部也会打印一些日志，这些日志对问题排查、业务监控、数据统计非常重要，但是这些数据的使用者通常是大数据团队、BI部分、架构团队等，因此规范这些日志的格式至关重要；此外格式统一，对于开发工程师跨团队协作也非常有益。

    原则不变：便于数据分拣、分域；不过为了更好的执行，在此之前，我们需要约定日志组件为logback + sl4j；因为我们会使用logback中的MDC机制，来打印更多的运行时信息。

<encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
    <pattern>%d{yyyy-MM-dd/HH:mm:ss.SSS}|%X{localIp}|%X{requestId}|%X{requestSeq}|^_^|uid:%X{uid}|^_^|[%t]|%-5level|%logger{50} %line - %m%n</pattern>
</encoder>

 

    整个过程中，我们将request_id从nginx传递到tomcat，在传递到java应用内部，主要是为后期的请求追踪平台做铺垫，同时我们排查问题也将更加容易。需要注意，%X{requestId}和%X{requestSeq}都是经过MDC Filter进行分装后的。

    在第二个域中，允许每个项目自定义各自的日志字段，为K-V模式，比如“uid:10010|orderId:10000”，K-V之间通过“:”分割，此后我们日志分析组件可以将它们解析成map并保存，比如保存在ES中。之所以这么做的原因是，每个业务系统需要打印的自定义字段各有不同，这对后续的数据分析和统计组件有较大的挑战，为了简化后续操作，我们将用户自定义字段部分结构松耦合。

 

    在上文中，我们还提到业务日志的大小问题，这就需要采用一定的rolling策略，我们约定所有项目的logback组件的版本不低于1.1.7，并统一rolling策略：

<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <file>${LOG_HOME}/order-center.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
        <fileNamePattern>${LOG_HOME}/order-center.log.%d{yyyy-MM-dd}.%i</fileNamePattern>
        <maxFileSize>256MB</maxFileSize>
        <maxHistory>15</maxHistory>
        <totalSizeCap>32GB</totalSizeCap>
    </rollingPolicy>
….
</appender>

 

4、基础数据平台规划

    1）基于Flume组件，对全网项目的日志文件进行收集，包括历史文件（每天rotate生成的、rolling生成的文件）和实时日志信息（tail）；将日志文件统一保存在一个或者多个堡垒机（group server）上，并将日志按照项目、时间进行归类。

    2）业务系统通常是分布式部署，一个project部署在多个机器上，每个机器都会产生新的日志信息，如果遇到线上问题，排查期间需要访问多个机器，为了解决这个问题，我们将每个项目实时产生的日志信息，统一汇总在堡垒机上一个文件中，比如：堡垒机上的/order-center/2017-10-11/access.log.tail，此文件保存了order-center项目中2017-10-11，多个tomcat实时的日志，它们混合在一起。

    3）Flume将实时日志转发到kafka中，其他数据统计、分析系统通过kafka消费数据。此外我们的Flume将采用“多层”架构设计，每个application宿主机器上部署一个Flume agent，同一个项目的agent将数据发给一个Flume collector（也是一个Flume agent），并统一由collector对日志信息进行分类、本地存储、Filter、以及转发给kafka等。

    4）基于storm + kafka对实时日志信息进行分析，并根据规则匹配日志内容，当遇到“业务异常”、“流量异常”等情况是，触发报警，并将相应的信息进行整理，形成traceing link并展示给相关人员。

评论

2 楼 QING____ 2017-01-21  

hao_foo 写道

日志收集、分析、监控？ 好像跟ELK 功能很相似。期待...

是的，前期将全链路的日志进行规范和统一，然后使用ELK、KAFKA、flume、storm/Spark进行分析或者展示，最终解决业务监控、数据分析、日志收集等特性。

1 楼 hao_foo 2017-01-16  

日志收集、分析、监控？ 好像跟ELK 功能很相似。期待...