全链路日志追踪-trace_id方式
全链路日志追踪过程：
nginx---> 网关--->服务A----服务.......
1、nginx相关配置
(1) nginx.conf
# HTTPS server
server {
listen 443 ssl http2;
server_name mp-sit.smartmidea.net;
ssl_protocols TLSv1.1 TLSv1.2;
ssl_certificate smartmidea.net.cer;
ssl_certificate_key smartmidea.net.key;
ssl_session_cache shared:SSL:1m;
ssl_session_timeout 5m;
ssl_ciphers HIGH:!aNULL:!MD5;
ssl_prefer_server_ciphers on;
include /apps/svr/nginx-1.17.5/conf/log_trace_proc.conf; //此文件是申城trace_id 、trace_path 具体内容如下
###########
set $trace_id $http_mc_trace_id;
set $trace_path $http_mc_trace_path;
set $curr_path "$msec:nginx:${server_addr}:${server_port}";
if ($trace_id != ''){
set $trace_path "${trace_path}${dollar}${curr_path}";
}
if ($trace_id = '') {
set $trace_id $request_id; //nginx版本要求（>1.11.0,下图为nginx官方关于$request_id申城唯一标识
set $trace_id "${trace_id}${dollar}${trace_id}"; // ${dollar}=$
set $trace_path "${curr_path}";
}
###########
include /apps/svr/nginx-1.17.5/conf/vhost.conf;
}
#日志格式及通用变量配置
log_format trace_log 'mp-nginx|$trace_id|$trace_path|$remote_addr|'
'$server_addr|$server_port|$http_traceId|$msec|$request_time|'
'$request_method|$request_uri|$status|$request_length|$body_bytes_sent|'
'$http_referer|$http_user_agent|$upstream_addr|$http_host';
access_log /apps/svr/nginx-1.17.5/logs/tracelog-mp-nginx.log trace_log;
}
(2) vhost.conf
location = /service {
proxy_redirect off;
proxy_ignore_client_abort on;
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-Forwarded-Proto $scheme;
proxy_set_header mc-trace-id $trace_id;
proxy_set_header mc-trace-path $trace_path; //mc-trace-id mc-trace-path 在头部转发到对应服务中；
(3) nginx日志位置：
2、服务A获取日志并打印到对应文件夹位置
(1) log4配置文件如下
<?xml version="1.0" encoding="UTF-8"?>
<!-- Configuration后面的status，这个用于设置log4j2自身内部的信息输出，可以不设置，当设置成trace时，
你会看到log4j2内部各种详细输出。可以设置成OFF(关闭) 或 Error(只输出错误信息)。
30s 刷新此配置
-->
<configuration status="WARN" monitorInterval="30">
<!-- 日志文件目录、压缩文件目录、日志格式配置 -->
<properties>
<Property name="modelName">服务A</Property>
<Property name="fileName">/apps/logs/${modelName}</Property>
<Property name="fileGz">/apps/logs/${modelName}</Property>
<Property name="LOG_PATTERN">%d{yyyy-MM-dd HH:mm:ss.SSS} %5p -%X{requestId}- [%15.15t] %-40.40c{1.} : %m%n%xwEx</Property>
</properties>
<Appenders>
<!-- 输出控制台日志的配置 -->
<Console name="console" target="SYSTEM_OUT">
<!--控制台只输出level及以上级别的信息（onMatch），其他的直接拒绝（onMismatch）-->
<ThresholdFilter level="debug" onMatch="ACCEPT" onMismatch="DENY"/>
<!-- 输出日志的格式 -->
<PatternLayout pattern="${LOG_PATTERN}"/>
</Console>
<!-- 打印出所有的信息，每次大小超过size，则这size大小的日志会自动存入按年份-月份建立的文件夹下面并进行压缩，作为存档 -->
<RollingRandomAccessFile name="infoFile" fileName="${fileName}/${modelName}-info.log" immediateFlush="false"
filePattern="${fileGz}/$${date:yyyy-MM}/${modelName}-info-%d{yyyy-MM-dd}-%i.log.gz">
<PatternLayout pattern="${LOG_PATTERN}"/>
<Policies>
<SizeBasedTriggeringPolicy size="32 MB"/>
</Policies>
<Filters>
<ReportLogFilter onMatch="DENY" onMismatch="ACCEPT" /> //info日志 ReportLogFilter 过滤掉
<!-- 只记录info和warn级别信息 -->
<!--<ThresholdFilter level="error" onMatch="DENY" onMismatch="NEUTRAL"/>-->
<ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
</Filters>
<!-- 指定每天的最大压缩包个数，默认500个，超过了会覆盖之前的 -->
<!-- <DefaultRolloverStrategy max="500"/>-->
</RollingRandomAccessFile>
<!-- 存储所有error信息 -->
<RollingRandomAccessFile name="errorFile" fileName="${fileName}/${modelName}-error.log" immediateFlush="false"
filePattern="${fileGz}/$${date:yyyy-MM}/%d{yyyy-MM-dd}-%i.${modelName}-error.gz">
<PatternLayout pattern="${LOG_PATTERN}"/>
<Policies>
<SizeBasedTriggeringPolicy size="32 MB"/>
</Policies>
<Filters>
<!-- 只记录error级别信息 -->
<ThresholdFilter level="error" onMatch="ACCEPT" onMismatch="DENY"/>
</Filters>
<!-- 指定每天的最大压缩包个数，默认500个，超过了会覆盖之前的 -->
<!--<DefaultRolloverStrategy max="500"/>-->
</RollingRandomAccessFile>
<!-- 记录上报日志 -->
<RollingRandomAccessFile name="reportFile" fileName="${fileName}/${modelName}-report.log" immediateFlush="false"
filePattern="${fileGz}/$${date:yyyy-MM}/%d{yyyy-MM-dd}-%i.${modelName}-report.gz">
<Policies>
<SizeBasedTriggeringPolicy size="100 MB"/>
</Policies>
<Filters>
<ReportLogFilter onMatch="ACCEPT" onMismatch="DENY" />
<ThresholdFilter level="info" onMatch="ACCEPT" onMismatch="DENY"/>
</Filters>
<DefaultRolloverStrategy max="100"/>
</RollingRandomAccessFile>
</Appenders>
<!-- Mixed sync/async -->
<Loggers>
<AsyncRoot level="info">
<AppenderRef ref="infoFile"/>
<AppenderRef ref="reportFile"/>
<AppenderRef ref="errorFile"/>
</AsyncRoot>
</Loggers>
</configuration>
(2) ReportLogFilter 过滤器
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Marker;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.Logger;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.config.plugins.PluginAttribute;
import org.apache.logging.log4j.core.config.plugins.PluginFactory;
import org.apache.logging.log4j.core.filter.AbstractFilter;
import org.apache.logging.log4j.message.Message;
@Plugin(
name = "ReportLogFilter",
category = "Core",
elementType = "filter",
printObject = true
)
public final class ReportLogFilter extends AbstractFilter { // 参照ThresholdFilter
private ReportLogFilter(Result onMatch, Result onMismatch) {
super(onMatch, onMismatch);
}
@Override
public Result filter(Logger logger, Level testLevel, Marker marker, String msg, Object... params) {
return this.filter(marker);
}
@Override
public Result filter(Logger logger, Level testLevel, Marker marker, Object msg, Throwable t) {
return this.filter(marker);
}
@Override
public Result filter(Logger logger, Level testLevel, Marker marker, Message msg, Throwable t) {
return this.filter(marker);
}
@Override
public Result filter(LogEvent event) {
return filter(event.getMarker());
}
private Result filter(Marker marker) {
return marker != null && ReportLog.isReport(marker.getName()) ? this.onMatch : this.onMismatch;
}
@PluginFactory
public static ReportLogFilter createFilter(@PluginAttribute("onMatch") Result match, @PluginAttribute("onMismatch") Result mismatch) {
Result onMatch = match == null ? Result.NEUTRAL : match;
Result onMismatch = mismatch == null ? Result.DENY : mismatch;
return new ReportLogFilter(onMatch, onMismatch);
}
}
A -> B -> C
我们需要将A/B/C/三个微服务间的日志按照链式打印，我们都知道Dubbo的RpcContext只能做到消费者和提供者共享同一个RpcContext，比如A->B，那么A和B都可以获取相同内容的RpcContext，但是B->C时，A和C就无法共享相同内容的RpcContext了，也就是无法做到链式打印日志了。
我们可以用左手交换右手的思路来解决，假设左手是线程的ThreadLocal，右手是RpcContext，那么在交换之前，我们首先将必要的日志信息保存到ThreadLocal中。
(3) 服务A 过滤器 --------TraceLogFilter
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.beans.factory.annotation.Value;
import org.springframework.boot.web.servlet.FilterRegistrationBean;
import org.springframework.context.annotation.Bean;
import org.springframework.stereotype.Component;
import org.springframework.web.method.HandlerMethod;
import org.springframework.web.servlet.mvc.method.RequestMappingInfo;
import org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerMapping;
import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
import java.util.Map;
import java.util.concurrent.ConcurrentHashMap;
@Component
public class TraceLogFilter implements Filter {
@Autowired
private RequestMappingHandlerMapping requestMappingHandlerMapping;
@Value("${spring.application.name}")
private String appName;
private static Map<String, String> REQUEST_METHOD = new ConcurrentHashMap<>(16);
private static Map<String, String> REQUEST_RESTFUL_METHOD = new ConcurrentHashMap<>(16);
@Override
public void init(FilterConfig filterConfig) throws ServletException {
LogTrace.init(appName);
initRequestMethod();
}
@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
BaseHttpRequestWarp requestWarp = new BaseHttpRequestWarp((HttpServletRequest)request);
BaseHttpResponseWrap responseWrap = new BaseHttpResponseWrap((HttpServletResponse)response);
try{
LogTrace.startHttp(requestWarp);
LogTrace.setCallMethod(matchCallMethod(requestWarp.getRequestURI()));
}catch (Exception ignore){}
chain.doFilter(requestWarp, responseWrap);
try{
LogTrace.stopHttp(responseWrap);
}catch (Exception ignore){}
}
private String matchCallMethod(String url) {
if (REQUEST_METHOD.get(url) != null){
return REQUEST_METHOD.get(url);
}
for(Map.Entry<String, String> entry : REQUEST_RESTFUL_METHOD.entrySet()){
if (matchUrl(entry.getKey(), url)){
return entry.getValue();
}
}
return null ;
}
private boolean matchUrl(String url, String tarUrl){
String[] tarUrlPiece = tarUrl.split("/");
String[] urlPiece = url.split("/");
boolean match = false;
for (int i=0; i<urlPiece.length; i++){
match = false;
if (i >= tarUrlPiece.length){
break;
}
if (urlPiece[i].equals(tarUrlPiece[i]) || (urlPiece[i].startsWith("{") && urlPiece[i].endsWith("}"))){
match = true;
continue;
}
break;
}
return match;
}
@Override
public void destroy() {
}
@Bean
public FilterRegistrationBean registerFilter() {
FilterRegistrationBean registration = new FilterRegistrationBean();
registration.setFilter(this);
registration.addUrlPatterns("/*");
registration.setName("traceLogFilter");
registration.setOrder(1);
return registration;
}
private void initRequestMethod(){
Map<RequestMappingInfo, HandlerMethod> map = requestMappingHandlerMapping.getHandlerMethods();
for (Map.Entry<RequestMappingInfo, HandlerMethod> m : map.entrySet()){
RequestMappingInfo info = m.getKey();
HandlerMethod method = m.getValue();
for(String url : info.getPatternsCondition().getPatterns()){
if (url.matches("(.*?)\\{(.*?)}(.*?)")){
REQUEST_RESTFUL_METHOD.put(url, String.format("%s.%s", String.valueOf(method.getBean()), method.getMethod().getName()));
}
REQUEST_METHOD.put(url, String.format("%s.%s", String.valueOf(method.getBean()), method.getMethod().getName()));
}
}
}
private void setAppName(String appName) {
this.appName = appName;
}
}
(4) LogTrace 实体类
import com.alibaba.fastjson.JSONObject;
import org.springframework.util.StringUtils;
import java.util.UUID;
public class LogTrace {
private static final String DEFAULT_TRACE_ID = "mc-trace-id";
private static final String DEFAULT_TRACE_PATH = "mc-trace-path";
public static String TRACE_ID() {
// 后续放入配置
return DEFAULT_TRACE_ID;
}
public static String TRACE_PATH() {
// 后续放入配置
return DEFAULT_TRACE_PATH;
}
private static ThreadLocal<LogTraceEntity> logVo = new ThreadLocal<LogTraceEntity>();
private static String logAppName = "default-trace-app";
{
String tmp = System.getProperty("java.class.path");
if(!StringUtils.isEmpty(tmp)) {
String[] ary = tmp.split("/");
logAppName = ary[ary.length-1];
}
}
public static void init(String appName) {
logAppName = appName;
}
public static void startHttp(IHttpRequest request) {
String serverIp = request.localHost();
int serverPort = request.localPort();
LogTraceEntity log = new LogTraceEntity();
log.setRequestTime(System.currentTimeMillis());
log.setAppName(logAppName);
// log.setClientIp(request.remoteAddress().host());
log.setClientIp(getClientIp(request));
log.setClientPort(request.remotePort());
log.setServerIp(serverIp);
log.setServerPort(serverPort);
log.setMethod(request.method());
long requestLen = request.contentLength();
log.setRequestLength(requestLen);
String traceId = request.getHeader(TRACE_ID());
String tracePath = request.getHeader(TRACE_PATH());
if (StringUtils.isEmpty(traceId)) {
traceId = UUID.randomUUID().toString().replace("-", "");
traceId += "$" + traceId;
tracePath = "";
} else {
tracePath += "$";
}
tracePath = String.format("%s%s:%s:%s:%s", tracePath, System.currentTimeMillis(), logAppName, serverIp,
serverPort);
log.setTraceId(traceId);
log.setTracePath(tracePath);
log.setUrl(request.path());
log.setQueryParams(request.query());
logVo.set(log);
}
public static void stopHttp(IHttpResponse response) {
LogTraceEntity log = logVo.get();
if (log == null) {
return;
}
log.setElapsedTime(System.currentTimeMillis() - log.getRequestTime());
log.setStatusCode(response.statusCode());
log.setResponseLength(response.contentLength());
// 从content中提取内容和businessCode
String content = response.content();
if (!StringUtils.isEmpty(content)) {
JSONObject resJson = JSONObject.parseObject(content);
log.setBusinessCode(resJson.getString("code"));
if (content.length() > 300) {
content = content.substring(0, 300);
}
log.setReturnContent(content);
}
ReportLog.report(log.toString()); //打印report日志
logVo.remove(); //释放ThreadLocal
}
private static String getClientIp(IHttpRequest request) {
String ip = request.getHeader("X-Forwarded-For");
ip = getIpFromHeaderIfNotAlreadySet("X-Real-IP", request, ip);
ip = getIpFromHeaderIfNotAlreadySet("Proxy-Client-IP", request, ip);
ip = getIpFromHeaderIfNotAlreadySet("WL-Proxy-Client-IP", request, ip);
ip = getIpFromHeaderIfNotAlreadySet("HTTP_CLIENT_IP", request, ip);
ip = getIpFromHeaderIfNotAlreadySet("HTTP_X_FORWARDED_FOR", request, ip);
ip = getFirstIp(ip);
if (ip == null || ip.length() == 0 || "unknown".equalsIgnoreCase(ip) || "127.0.0.1".equalsIgnoreCase(ip)) {
ip = request.remoteHost();
}
return ip;
}
private static String getFirstIp(String ip) {
if (ip != null) {
final int indexOfFirstComma = ip.indexOf(',');
if (indexOfFirstComma != -1) {
ip = ip.substring(0, indexOfFirstComma);
}
}
return ip;
}
private static String getIpFromHeaderIfNotAlreadySet(String header, IHttpRequest request, String ip) {
if (StringUtils.isEmpty(ip) || "unknown".equalsIgnoreCase(ip)) {
ip = request.getHeader(header);
}
return ip;
}
public static void startRpc(String serverIp, int serverPort, String remoteAddr) {
LogTraceEntity log = new LogTraceEntity();
log.setRequestTime(System.currentTimeMillis());
log.setAppName(logAppName);
String[] ary = StringUtils.isEmpty(remoteAddr) ? "".split(":") : remoteAddr.split(":");
log.setClientIp(ary[0]);
try {
if (ary.length > 1) {
log.setClientPort(Integer.valueOf(ary[1]));
} else {
log.setClientPort(0);
}
} catch (Exception ex) {
}
log.setServerIp(serverIp);
log.setServerPort(serverPort);
logVo.set(log);
}
public static void updateRpc(String traceId, String tracePath, String method, long requestLen) {
LogTraceEntity log = logVo.get();
log.setMethod(method);
log.setRequestLength(requestLen);
if (StringUtils.isEmpty(traceId)) {
traceId = UUID.randomUUID().toString().replace("-", "");
traceId += "$" + traceId;
tracePath = "";
} else {
tracePath += "$";
}
tracePath = String.format("%s%s:%s:%s:%s", tracePath, System.currentTimeMillis(), logAppName, log.getServerIp(),
log.getServerPort());
log.setTraceId(traceId);
log.setTracePath(tracePath);
log.setUrl(method);
}
public static void stopRpc(String callMethod, int statusCode, long respLength, String content) {
LogTraceEntity log = logVo.get();
if (log == null) {
return ;
}
if(!StringUtils.isEmpty(callMethod)) {
log.setCallMethod(callMethod);
}
log.setElapsedTime(System.currentTimeMillis() - log.getRequestTime());
log.setStatusCode(statusCode);
if (log.getBusinessCode() == null || log.getBusinessCode().isEmpty()) {
log.setBusinessCode(String.valueOf(statusCode));
}
log.setResponseLength(respLength);
// 从content中提取内容和businessCode
if (!StringUtils.isEmpty(content)) {
if (content.length() > 300) {
content = content.substring(0, 300);
}
log.setReturnContent(content);
}
ReportLog.report(log.toString());
}
public static LogTraceEntity get() {
return logVo.get();
}
public static void putData(String key, String val) {
LogTraceEntity log = logVo.get();
if (log != null && !StringUtils.isEmpty(key) && !StringUtils.isEmpty(val)) {
log.pubQueryData(key, val);
}
}
public static void getData(String key) {
LogTraceEntity log = logVo.get();
if (log != null) {
log.getQueryData(key);
}
}
public static void setCallMethod(String callMethod) {
LogTraceEntity log = logVo.get();
if (log != null) {
log.setCallMethod(callMethod);
}
}
public static String getTraceId() {
LogTraceEntity log = logVo.get();
if (log != null) {
return log.getTraceId();
} else {
return "";
}
}
public static String getTracePath() {
LogTraceEntity log = logVo.get();
if (log != null) {
return log.getTracePath();
} else {
return "";
}
}
public static void setBusinessCode(String businessCode) {
LogTraceEntity log = logVo.get();
if (log != null) {
log.setBusinessCode(businessCode);
}
}
}
(5) ReportLog 实体类
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.Marker;
import org.slf4j.MarkerFactory;
public class ReportLog {
private static final Logger LOGGER = LoggerFactory.getLogger(ReportLog.class);
private static final Marker REPORT_MARKER = MarkerFactory.getMarker("服务A-REPORT");
public static void report(String log){
LOGGER.info(REPORT_MARKER, log);
}
public static boolean isReport(String name){
return REPORT_MARKER.getName().equals(name);
}
}
打印日志：
2020-04-22 14:29:18.521 INFO -- [nio-7272-exec-7] c.m.p.m.l.ReportLog : 1587536958480|muc-application|0b0391c76aab4271887d6b1d1d78ce6e$0b0391c76aab4271887d6b1d1d78ce6e|1587536958480:服务A-application:0:0:0:0:0:0:0:1:7272||0:0:0:0:0:0:0:1|51387|0:0:0:0:0:0:0:1|7272|31|151|76|POST|/muc/v5/app/mj/user/getOpenIds|404|null|null|404|{"code":404,"msg":"资源不存在","data":"/muc/v5/app/mj/user/getOpenIds"}
(6) 服务A日志
drwxr-xr-x 2 root root 12288 Mar 31 17:27 2020-03
drwxr-xr-x 2 root root 4096 Apr 22 10:15 2020-04
-rw-r--r-- 1 root root 22725584 Apr 22 11:09 服务A-error.log
-rw-r--r-- 1 root root 29789214 Apr 22 14:33 服务A--info.log
-rw-r--r-- 1 root root 50306628 Apr 18 16:02 服务A--report.log
