nginx-链路追踪(trace)实现

一. 需求场景：

在日常运维工作中，会经常遇到在有多重调用链的场景下，如请求遇到非致命error时，在各环节的定位会非常麻烦，举个例子：比如说，在一个有多重调用链的服务环境下，一个请求正常的处理时间是1s，但某一天，某一时刻，有个别的请求出现长时间的延迟/响应慢的情况，这时，如果想在系统/服务无明显瓶颈的情况下，会非常难定位到具体在请求的哪一个环节出了问题，导致处理过慢，对于这种需求，就需要对这类多重调用链的服务做请求追踪，既：为每一个请求打一个标识，相当于牵一根线，不管请求走到哪一步，都会知道处理的请求对应上游请求是哪一个，从而快速定位出问题节点。

二. 环境实现：

不同环境可能存在差异，重在提供思路，抛砖引玉。

整体的多重调用链机制，是需要和相关研发同学配合实现的(比如：需要研发同学添加相应的trace到request的head)，运维需要做的是在我们维护的服务中做相应配置；我们的业务前端统一使用了nginx作为代理层，在nginx中，1.11版本后有一个$request_id可以解决这个问题(为请求生成一个请求id)，如果是1.11之前的，就需要我们采用自定义/多重组合的方式来生成一个唯一性的trace_id了：

[/etc/nginx]#vim trace.setting    #定义trace配置set $request_trace_id $http_x_request_id;     #定义trace id号(请求head中的request_id [需要开发add])
set $request_trace_seq $http_x_request_req;   #定义trace调用的次数(会由研发进行+1操作[除自己编写插件外，暂未在nginx中发现有相关方式])if ( $request_trace_id = '' ) {               #当id为null，即：首次访问set $request_trace_id $pid-$connection-$bytes_sent-$msec;      #组合生成trace id
}
if ( $request_trace_seq = '' ) {              #当req为null，即：首次访问set  $request_trace_seq 0;                 #设置req 为0 
}

加载方式：

server {listen       80;server_name  elk.xxx.com.cn;include trace.setting;access_log  /var/log/nginx/access_elk.log  main;if ($ip_whitelist = 0){return  403;}location / {proxy_pass         http://elk_xxx_com_cn;proxy_set_header   Host             $host;proxy_set_header   X-Real-IP        $remote_addr;proxy_set_header   X-Forwarded-For  $proxy_add_x_forwarded_for;proxy_set_header   X-Request-ID $request_trace_id;proxy_set_header   X-Request-Seq $request_trace_seq;}

log format：

    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_parentId|$cookie_studentId|$cookie_mbparentid|$cookie_mbstudentid';

(其中$upstream_connect_tme[nginx 1.9.1版本添加]记录了链接upstream后端机器的时间)

生成log：

08/Feb/2017:15:41:24 +0800|ip-10-0-2-11|10.0.1.22|10.0.4.133:8080|0.013|0.013|0.000|200|200|-|1126|-|-|-|GET /restt?studentId=1244691&teacherId=2957149&startTime=1486569600000&endTime=1486656000000&t=1486539670308 HTTP/1.1|Mozilla/5.0 (Windows NT 10.0; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/56.0.2924.87 Safari/537.36|http://www.xxx.com.cn/|^_^|http|GET|39144-539579249-0-1486539684.574|0|^_^|36.110.67.3|parent 1929119 16998165-14d1-4300-93b1-92f89c7275b4|1929119|1244691|-|-

后端tomcat 配置(access_log)：

        <Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs"prefix="localhost_access_log" suffix=".txt"pattern="%h %m %t %D "%r" "%{Referer}i" "%{User-Agent}i" %s %S %b %{X-Request-ID}i %{begin:msec}t %{end:msec}t" />

其他技术栈的，请自行定义。

生成log如下：

10.0.1.12 GET [27/Nov/2016:20:54:17 +0800] 172 "GET /parent/lessons HTTP/1.1" "http://www.vipkid.com.cn/parent/home" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.101 Safari/537.36" 200 659942FB586A3639FC096192897382F2 14461 44765-20012801-0-1480251341.490 1480251257008 1480251257180

----------------------------------------------------------------------------------------------

深耕运维行业多年，擅长linux、容器云原生、运维自动化等方面。
承接各类运维环境部署、方案设计/实施、服务代运维工作，欢迎沟通交流！