微服務應用日誌處理與組件封裝

微服務應用日誌組件定製

隨着微服務等設計理念在系統中的應用，業務的調用鏈愈來愈複雜，日誌信息愈來愈大，從快速增加的日誌數據流中提取出所需的信息，並將其與其餘相關聯的事件進行關聯，將變得越加困難.ELK + KAFKA做爲微服務應用日誌中心解決方案是業界常規辦法，前提是應用日誌輸出的規範化，日誌組件就是爲了完成這一目標。

微服務應用日誌格式規劃

通過公司技術人員充分討論和分析，確認了應用日誌輸出格式以下：

|時間|日誌級別|線程名|代碼發生行|同步調用ID|客戶系統節點|服務系統節點|客戶系統名稱|服務系統名稱|日誌類型|全局流水號|定製化字段^日誌信息| 

• 時間：記錄日誌產生時間;
• 日誌級別：致命，ERROR，WARN，INFO，DEBUG;
• 線程名：執行操做線程名稱;
• 代碼發生行：日誌事件發生在代碼中位置;
• 同步調用ID：用於同步調用鏈分析，能夠關聯基普金，精肯定位等工具關聯排查問題;
• 客戶系統節點：表示服務 - 客戶端系統節點的標識，能夠爲IP或者DockerID;
• 服務系統節點：表示服務 - 服務端系統節點的標識，能夠爲IP或者DockerID;
• 客戶系統名稱：表示服務 - 客戶端系統的標識，能夠爲系統簡稱和全稱;
• 服務系統名稱：表示服務 - 服務端系統的標識，能夠爲系統簡稱和全稱;
• 全局流水號：貫穿一次業務流程的全局流水號;
• 日誌類型：枚舉，REQ-接口請求報文，RESP-接口響應報文，BIZ-通用日誌;
• INFO：定製化字段（格式採用關鍵字段=值，關鍵字段2 =值）^業務信息（記錄詳細日誌信息）。

舉個栗子：

|2018-03-28 14:26:21.001|INFO|demo-service-woker:share-d-3[share]-thread-1|com.xxxx.xxx.service.interceptor.ParamCheckInterceptor:59:doInvoke|4507080825331412517041832|127.0.0.1:50344|127.0.0.1:20015|demo-a|demo-b|20170428142618325183APP|BIZ|phoneNumber=185****1234, woAccountId=110000008592138^參數及權限校驗攔截，驗證經過.| 

日誌組件實現方案

Java的技術平臺日誌輸出組件主要有java.util.logging中，log4j的，log4j2，的logback，SLF4J。我司目前使用的log4j2 + SLF4J組合做爲應用日誌輸出組件，爲了實現上述日誌格式輸出，主要有兩種方式在組件上實現封裝，應用採用SpringBoot +寧靜做爲主框架

Log4J的的MDC方案

MDC [ http://logging.apache.org/log4j/1.2/apidocs/org/apache/log4j/MDC.html]是爲每一個線程創建一個獨立的存儲空間，開發人員能夠根據須要把信息存入其中.MDC使用Map機制來存儲信息，信息以鍵/值對的形式存儲在Map中。
使用Servlet過濾器或者AOP在服務接收到請求時，獲取須要的值填充MDC。在log4j2的配置中就可使用％ X {}鍵MDC打印中的內容，從而識別出同一次請求中的日誌。

Log4j2.X版本

MdcLogfilter類

public class MdcLogfilter implements Filter { public static final String TRACE_ID = "traceId"; public static final String CLIENT_ADDR = "clientAddr"; public static final String SERVER_ADDR = "serverAddr"; public static final String CLIENT_SYS_NAME = "clientSysName"; public static final String SERVER_SYS_NAME = "serverSysName"; public static final String TRANS_ID = "transId"; public static final String LOG_TYPE = LogTypeEnum.BIZ.getKey(); private String systemName; public MdcLogfilter( String systemName ) { this.systemName = systemName; } @Override public void init( FilterConfig filterConfig ) throws ServletException { } @Override public void doFilter( ServletRequest request, ServletResponse response, FilterChain chain ) throws IOException, ServletException { try { insertIntoMDC(request); chain.doFilter(request, response); } finally { ThreadContext.clearAll(); } } @Override public void destroy() { } protected void insertIntoMDC( ServletRequest request ) { HttpServletRequest httpRequest = (HttpServletRequest) request; String traceId = httpRequest.getHeader(TRACE_ID); String clientAddr = httpRequest.getRemoteAddr(); String serverAddr = getSreverAddr(); String clientSysName = httpRequest.getHeader(CLIENT_SYS_NAME); String serverSysName = systemName; String transId = (String) httpRequest.getAttribute(TRANS_ID); ThreadContext.put(TRACE_ID, traceId); ThreadContext.put(CLIENT_ADDR, clientAddr); ThreadContext.put(SERVER_ADDR, serverAddr); ThreadContext.put(CLIENT_SYS_NAME, clientSysName); ThreadContext.put(SERVER_SYS_NAME, serverSysName); ThreadContext.put(TRANS_ID, transId); ThreadContext.put(LOG_TYPE, LogTypeEnum.REQ.getKey()); } private String getServerAddr() { return null; } } 

MDCLogAspect類

@Aspect public class MDCLogAspect { private static final Logger LOGGER = LoggerFactory.getLogger(EpayLogAspect.class); private static long STIME = LogUtil.getNowTimeInMillis(); private static String REQUESTURL = "url"; @Pointcut("execution(public * com.demo..*.*.controller.*.*(..))") public void log() { } @Before("log()") public void deBefore( JoinPoint joinPoint ) throws Throwable { STIME = LogUtil.getNowTimeInMillis(); ServletRequestAttributes attributes = (ServletRequestAttributes) RequestContextHolder.getRequestAttributes(); HttpServletRequest request = attributes.getRequest(); Map<String, String[]> params = request.getParameterMap(); String queryString = ""; for (String key : params.keySet()) { String[] values = params.get(key); for (int i = 0; i < values.length; i++) { String value = values[i]; queryString += key + "=" + value + "&"; } } if (!StringUtils.isEmpty(queryString)){ queryString = queryString.substring(0, queryString.length() - 1); } REQUESTURL = request.getRequestURL().toString(); LOGGER.info("url：{}，req：{}", REQUESTURL, queryString); MDC.put(LogPreKeyConstants.LOGTYPE, LogTypeEnum.BIZ.getKey()); } @AfterReturning(returning = "ret", pointcut = "log()") public void doAfterReturning( Object ret ) throws Throwable { MDC.put(LogPreKeyConstants.LOGTYPE, LogTypeEnum.RESP.getKey()); LOGGER.info("url：{}，resp：{}", REQUESTURL, ret); MDC.remove(LogPreKeyConstants.LOGTYPE); MDC.put(LogPreKeyConstants.LOGTYPE, LogTypeEnum.BIZ.getKey()); } //後置異常通知 @AfterThrowing("log()") public void throwss( JoinPoint jp ) { String costtime = LogUtil.getNowTimeInMillis() - STIME + "ms"; LOGGER.info("url：{}，executetime：{}", REQUESTURL, costtime); } //後置最終通知,final加強，無論是拋出異常或者正常退出都會執行 @After("log()") public void after( JoinPoint jp ) { String costtime = LogUtil.getNowTimeInMillis() - STIME + "ms"; LOGGER.info("url：{}，executetime：{}", REQUESTURL, costtime); } } 

Log4j1.X版本

log4j1.x版本，ThreadContext類換成MDC便可

log4j的配置使用MDC

在log4j配置中，使用mdc：（log4j 1.x與2.x中均可以使用此配置）

<PatternLayout pattern="|%d{yyyy-MM-dd HH:mm:ss.SSS}|%5p|%5t|%4c:%L|%X{traceid}|%X{clientaddr}|%X{serveraddr}|%X{cientsysname}|%X{serversysname}|%X{transid}|%X{logType}|%m|%n" /> 

Springboot使用

實現定製化登陸開始，應用依賴便可。

Log4J的的適配器封裝方案

使用適配器模式封裝log4j的接口，使用AOP在服務接收到請求時，獲取須要的值填充本地線程副本中，打印日誌時候拼接輸出到日誌。

Log4j2.X / Log4j1.X版本

LogContextHolder

public class AdapterLogContextHolder { private static final ThreadLocal<AdapterLogContext> LOG_CONTEXT = new ThreadLocal<>(); private static AdapterLogContextHolder context = new AdapterLogContextHolder(); private AdapterLogContextHolder() { } public static AdapterLogContextHolder getInstance() { return context; } public AdapterLogContext getLogContext() { AdapterLogContext context = LOG_CONTEXT.get(); if (context == null) { context = new AdapterLogContext(); LOG_CONTEXT.set(context); } return context; } public void setLogContext( AdapterLogContext context ) { LOG_CONTEXT.set(context); } public void removeLogContext() { LOG_CONTEXT.remove(); } public String getTraceID() { return getLogContext().getTraceID(); } public void setTraceID( String id ) { getLogContext().setTraceID(id); } } 

AdapterLogContext

public class AdapterLogContext implements Serializable, Cloneable { private static final long serialVersionUID = 6126191683350551062L; private String traceID = "traceID"; private long callStartTimes; private String transID = "transId"; private String clientAddr = "clientAddr"; private String serverAddr = "serverAddr"; private String clientSysName = "clientSysName"; private String serverSysName = "serverSysName"; @Override public Object clone() throws CloneNotSupportedException { return super.clone(); } //get、set ..... } 

LoggerAdapter

public class LoggerAdapter { final static String FQCN = LoggerAdapter.class.getName(); private static LoggerAdapter loggerAdapter; private static volatile HashMap<String, LoggerAdapter> loggerxMap = null; protected Logger logger = null; private LoggerAdapter( Logger logger ) { this.logger = logger; } public static LoggerAdapter getLogger( Class<?> classObject ) { if (null == classObject) { throw new IllegalArgumentException(); } if (loggerxMap == null) { synchronized (Loggerx.class) { if (loggerxMap == null) { loggerxMap = new HashMap<>(); return getLoggerAdapter(classObject); } } } LoggerAdapter loggerAdapter = loggerxMap.get(classObject.getSimpleName()); if (loggerAdapter == null) { return getLoggerAdapter(classObject); } else { return loggerAdapter; } } private static LoggerAdapter getLoggerAdapter( Class<?> classObject ) { Logger logger = LogManager.getLogger(classObject); if (logger == null) { return null; } LoggerAdapter loggerAdapter = new LoggerAdapter(logger); loggerxMap.put(classObject.getSimpleName(), loggerAdapter); return loggerAdapter; } public void info( LogType logType, Object message ) { String msgFormatted = msgFormat(logType, message); logger.log(FQCN, Level.INFO, msgFormatted, null); } public void info( LogType logType, Map<String, String> custMsg, Object message ) { String msgFormatted = msgFormat(logType, custMsg, message); logger.log(FQCN, Level.INFO, msgFormatted, null); } public void error( LogType logType, Object message ) { String msgFormatted = msgFormat(logType, message); logger.log(FQCN, Level.ERROR, msgFormatted, null); } public void error( LogType logType, Map<String, String> custMsg, Object message ) { String msgFormatted = msgFormat(logType, custMsg, message); logger.log(FQCN, Level.ERROR, msgFormatted, null); } public void error( LogType logType, Object message, Throwable t ) { String msgFormatted = msgFormat(logType, message); logger.log(FQCN, Level.ERROR, msgFormatted, t); } public void error( LogType logType, Map<String, String> custMsg, Object message, Throwable t ) { String msgFormatted = msgFormat(logType, custMsg, message); logger.log(FQCN, Level.ERROR, msgFormatted, t); } public void warn( LogType logType, Object message ) { String msgFormatted = msgFormat(logType, message); logger.log(FQCN, Level.WARN, msgFormatted, null); } public void warn( LogType logType, Map<String, String> custMsg, Object message ) { String msgFormatted = msgFormat(logType, custMsg, message); logger.log(FQCN, Level.WARN, msgFormatted, null); } public void debug( LogType logType, Object message ) { String msgFormatted = msgFormat(logType, message); logger.log(FQCN, Level.DEBUG, msgFormatted, null); } protected String msgFormat( LogType logType, Object message ) { StringBuilder sb = new StringBuilder(); AdapterLogContext logContext = AdapterLogContextHolder.getInstance().getLogContext(); sb.append(logContext.getTraceID()); sb.append("|").append(logContext.getClientAddr()); sb.append("|").append(logContext.getServerAddr()); sb.append("|").append(logContext.getClientSysName()); sb.append("|").append(logContext.getServerAddr()); sb.append("|").append(logContext.getTransID()); sb.append("|").append(logType); sb.append("|").append("custmsg=null"); sb.append(message != null ? "^" + message.toString().replaceAll("\r|\n", "").replaceAll("\\|", "#") + "|" : ""); return sb.toString(); } protected String msgFormat( LogType logType, Map<String, String> custMsgMap, Object message ) { if (custMsgMap == null || custMsgMap.isEmpty()) { return msgFormat(logType, message); } else { StringBuilder sb = new StringBuilder(); AdapterLogContext logContext = AdapterLogContextHolder.getInstance().getLogContext(); sb.append("|").append(logContext.getClientAddr()); sb.append("|").append(logContext.getServerAddr()); sb.append("|").append(logContext.getClientSysName()); sb.append("|").append(logContext.getServerAddr()); sb.append("|").append(logContext.getTransID()); sb.append("|").append(logType); sb.append("|"); for (Map.Entry<String, String> entry : custMsgMap.entrySet()) { sb.append(entry.getKey() + "=" + entry.getValue() + ","); } sb.deleteCharAt(sb.length() - 1); sb.append(message != null ? "^" + message.toString().replaceAll("\r|\n", "") + "|" : ""); return sb.toString(); } } } 

AOP切片類LoggerAdapter

public class ClientContextBeforeAdvice implements MethodBeforeAdvice { @Override public void before(Method arg0, Object[] arg1, Object arg2) throws Throwable { try { if (arg1.length == 0 || !(arg1[0] instanceof BaseRequest)) { return; } AdapterLogContext logContext = AdapterLogContextHolder.getInstance().getLogContext() //獲取logContext各個屬性值 BaseRequest request = (BaseRequest) arg1[0]; request.setLogContext(logContext); } catch (Exception e) { LOGGER.error(LogType.EX, "", e); throw e; } } } //其餘AOP切片 

log4j的配置使用適配器模式

在log4j配置中，log4j 1.x與2.x中均可以使用正常配置

Springboot使用

實現定製化登陸開始，應用依賴便可。

MDC方式與適配器方式對比

兩種對比，MDC優勢在於不改變開發人員使用的log4j方法，引入不須要更改業務代碼，適配器優點在於使用AOP和ThreadLocal的方式更方便定製化。我司目前使用MDC方案。