需求
自從公司采用微服務(wù)架構(gòu)以后,日志不好看了, 雖然已經(jīng)把所有日志都收集到了elk, 但是因?yàn)橐粋€(gè)前端的請(qǐng)求通過N個(gè)服務(wù),導(dǎo)致日志分布很零亂,沒有辦法顯示這一個(gè)請(qǐng)求相關(guān)的日志,所以需要開發(fā)一點(diǎn)小功能來(lái)實(shí)現(xiàn)單個(gè)請(qǐng)求的跟蹤.
設(shè)計(jì)
基本的想法是, 對(duì)每個(gè)請(qǐng)求設(shè)置一個(gè)RequestId, 然后讓這個(gè)id跟隨請(qǐng)求傳輸?shù)矫總€(gè)服務(wù),進(jìn)而打印到日志中. 需要解決以下問題:
1.請(qǐng)求id的隔離舷丹；
2.將自定義變量打印到日志中, 不能修改日志輸出函數(shù)残腌；
3.讓id跟隨請(qǐng)求到達(dá)每個(gè)服務(wù).
實(shí)現(xiàn)
請(qǐng)求id的隔離
每個(gè)請(qǐng)求都是單個(gè)線程處理的, 那么可以跟據(jù)這點(diǎn)來(lái)做請(qǐng)求id隔離, 即線程id->請(qǐng)求id, 對(duì)于每個(gè)新的請(qǐng)求,都生成一個(gè)請(qǐng)求id,然后將id保存到Map<線程id,請(qǐng)求id>中.
自定義變量打印到日志
當(dāng)前用的日志框架是log4j2, 通過查詢文檔和搜索資料, 發(fā)現(xiàn)log4j2的插件能實(shí)現(xiàn)這個(gè)功能: 具體文檔在 Log4j2 Converters
具體實(shí)現(xiàn)代碼如下:
import org.apache.commons.lang3.StringUtils;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.pattern.ConverterKeys;
import org.apache.logging.log4j.core.pattern.LogEventPatternConverter;
import org.apache.logging.log4j.core.pattern.PatternConverter;
import java.util.Random;
import java.util.concurrent.ConcurrentHashMap;
@Plugin(name = "LogRequestIdPlugin", category = PatternConverter.CATEGORY)
@ConverterKeys({"RequestId"})
public class LogRequestIdPlugin extends LogEventPatternConverter {
private static ConcurrentHashMap<Long, String> requestIdMap = new ConcurrentHashMap<>();
private static LogRequestIdPlugin instance = new LogRequestIdPlugin("RequestId", "RequestId");
/**
* Constructs an instance of LoggingEventPatternConverter.
*
* @param name name of converter.
* @param style CSS style for output.
*/
public LogRequestIdPlugin(String name, String style) {
super(name, style);
}
public static LogRequestIdPlugin newInstance(String[] params) {
return instance;
}
/**
* Formats an event into a string buffer.
*
* @param event event to format, may not be null.
* @param toAppendTo string buffer to which the formatted event will be appended. May not be null.
*/
@Override
public void format(LogEvent event, StringBuilder toAppendTo) {
toAppendTo.append(getRequestId());
}
/**
* 設(shè)置當(dāng)前線程的請(qǐng)求id
*
* @param requestId
*/
public static void setRequestId(String requestId) {
if (StringUtils.isEmpty(requestId)) {
requestIdMap.remove(Thread.currentThread().getId());
} else {
requestIdMap.put(Thread.currentThread().getId(), requestId);
}
}
/**
* 獲取當(dāng)前線程請(qǐng)求id
* 如果請(qǐng)求id不存在,則生成一個(gè)
*
* @return
*/
public static String getRequestId() {
String requestId = requestIdMap.get(Thread.currentThread().getId());
if (StringUtils.isEmpty(requestId)) {
requestId = newRequestId();
requestIdMap.put(Thread.currentThread().getId(), requestId);
}
return requestId;
}
private final static String charMap = "abcdefghijklmnopqrstuvwxyzABCDEFGHIJKLMNOPQRSTUVWXYZ0123456789";
private static String randomString(int length) {
Random random = new Random();
StringBuilder stringBuilder = new StringBuilder();
for (int i = 0; i < length; i++) {
stringBuilder.append(charMap.charAt(random.nextInt(charMap.length())));
}
return stringBuilder.toString();
}
/**
* 生成一個(gè)請(qǐng)求id
*
* @return
*/
public static String newRequestId() {
String timeHex = String.format("%x", System.currentTimeMillis() - 1513728000000L);
return randomString(6) + timeHex;
}
}
然后修改日志配置文件layout:
<PatternLayout pattern="[%RequestId] %d{HH:mm:ss.SSS} [%t] %-5level %logger{36} - %msg%n"/>
請(qǐng)求id跟隨請(qǐng)求到達(dá)每個(gè)服務(wù)
在當(dāng)前架構(gòu)中, 客戶的一個(gè)請(qǐng)求到達(dá)網(wǎng)關(guān)之后, 在每個(gè)服務(wù)之間的調(diào)用方式有:
controller層的http請(qǐng)求, dubbo請(qǐng)求和rocketmq消息殉挽；
在不能影響當(dāng)前業(yè)務(wù)的前提條件下, 怎么傳輸RequestId呢?
- controller層http請(qǐng)求:
在網(wǎng)關(guān)將RequestId放到header里面, 在接收端將RequestId取出來(lái)放到Map<線程id,請(qǐng)求id>中, 需要加一個(gè)web filter, 具體實(shí)現(xiàn)如下:
import cn.com.xxx.common.log.LogRequestIdPlugin;
import org.apache.commons.lang3.StringUtils;
import org.springframework.context.annotation.Configuration;
import javax.servlet.*;
import javax.servlet.annotation.WebFilter;
import javax.servlet.http.HttpServletRequest;
import java.io.IOException;
@Configuration
@WebFilter(urlPatterns = "/", filterName = "RequestIdLogFilter")
public class WebLogFilter implements Filter {
@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {
if (request instanceof HttpServletRequest) {
String requestId = ((HttpServletRequest) request).getHeader("RequestId");
if (StringUtils.isEmpty(requestId)) {
requestId = LogRequestIdPlugin.newRequestId();
}
LogRequestIdPlugin.setRequestId(requestId);
}
chain.doFilter(request, response);
}
@Override
public void init(FilterConfig filterConfig) throws ServletException {
}
@Override
public void destroy() {
}
}
- dubbo請(qǐng)求
dubbo請(qǐng)求可以使用過濾器,在消費(fèi)端放入RequestId, 在提供端接收RequestId, 具體實(shí)現(xiàn)如下:
import cn.com.xxx.common.log.LogRequestIdPlugin;
import com.alibaba.dubbo.common.Constants;
import com.alibaba.dubbo.common.extension.Activate;
import com.alibaba.dubbo.rpc.*;
import com.alibaba.dubbo.rpc.protocol.dubbo.DecodeableRpcInvocation;
import org.springframework.util.StringUtils;
@Activate(group = {Constants.PROVIDER, Constants.CONSUMER})
public class DubboLogFilter implements Filter {
@Override
public Result invoke(Invoker<?> invoker, Invocation invocation) throws RpcException {
if (invocation instanceof DecodeableRpcInvocation) {
String requestId = invocation.getAttachment("RequestId");
if (!StringUtils.isEmpty(requestId)) {
LogRequestIdPlugin.setRequestId(requestId);
}
} else {
invocation.getAttachments().put("RequestId", LogRequestIdPlugin.getRequestId());
}
return invoker.invoke(invocation);
}
}
3.rocketmq消息
rocketmq可以對(duì)每個(gè)消費(fèi)增加自定義變量,用來(lái)攜帶RequestId. 可以自定義公共發(fā)送和消費(fèi)類中處理RequestId, 因?yàn)槲覀儺?dāng)前沒有公共發(fā)送類 , 只有公共消費(fèi)類, 所以使用了aop來(lái)做處理, 具體實(shí)現(xiàn)如下:
import cn.com.xxx.common.log.LogRequestIdPlugin;
import org.apache.commons.lang3.StringUtils;
import org.apache.rocketmq.common.message.Message;
import org.apache.rocketmq.common.message.MessageExt;
import org.aspectj.lang.annotation.Aspect;
import org.aspectj.lang.annotation.Before;
import org.aspectj.lang.annotation.Pointcut;
import org.springframework.stereotype.Component;
@Aspect
@Component
public class RocketMQLogFilter {
@Pointcut("execution(public * org.apache.rocketmq.client.producer.DefaultMQProducer.send(" +
"org.apache.rocketmq.common.message.Message,..)) " +
"&& args(msg,..)")
private void sendMessage(Message msg) {
}
@Before(value = "sendMessage(msg)", argNames = "msg")
public void onSendMessage(Message msg) {
msg.putUserProperty("RequestId", LogRequestIdPlugin.getRequestId());
}
/**
* 消費(fèi)時(shí)調(diào)用, 放到公共庫(kù)中處理
*
* @param msg
*/
public static void onConsumeMessage(MessageExt msg) {
String requestId = msg.getUserProperty("RequestId");
if (!StringUtils.isEmpty(requestId)) {
LogRequestIdPlugin.setRequestId(requestId);
}
}
}
總結(jié)
一個(gè)簡(jiǎn)單的基于請(qǐng)求的日志跟蹤功能就這樣實(shí)現(xiàn)了, 雖然很簡(jiǎn)單, 但是對(duì)于查找問題還是非常有用的.
異步處理
日志處理異步輸出模式時(shí), 可以參考<<微服務(wù)基于請(qǐng)求的日志跟蹤2>>
