Abstract: The interface is designed to return the result value and encoding, and what other result parameters need to be optimized? How to implement log link tracing in microservices distributed architecture?

This document is shared in the huawei cloud community “How can I Implement Log Link Tracing in microservices Distributed Architecture?” , author: Code non architecture.

Logback background

Logback is another open source logging component designed by the founders of Log4j. Logback.qos.ch It is currently divided into the following modules:

  • Logback-core: The base module of the other two modules

  • Logback-classic: It is an improved version of Log4J and fully implements the SLF4J API so that you can easily switch to other Logging systems such as Log4J or JDK14 Logging

  • Logback-access: The access module integrates with the Servlet container to provide log access over Http

Ordinary Debug logs

SQL Execution log

Logback configuration case

Log levels are in the following order: TRACE < DEBUG < INFO < WARN < ERROR

  • %d: indicates the date

  • % n: a newline

  • %thread: indicates the name of the thread

  • %level: indicates the log level

  • % MSG: log message

  • %file: indicates the file name

  • %class: indicates the file name

  • %logger: Java class name (including package name, 36 bits, if more than 36 bits, package name will be reduced to a similar A.B.C. Javabeans)

  • %line: the line number of the Java class

Note:

%-4relative %d{yyyy-MM-dd HH:mm:ss.SSS} [%thread][%X{TRACE_ID}] %-5level %logger{100}.%M\(%line\) - %msg%n
Copy the code

In Logback, % relative indicates the relative timestamp (in milliseconds) printed since the application started. % -4 is simply the alignment of elements.

case

3452487 the 2021-08-03 15:19:36. 940 daemon] [thread - monitor - [] WARN com.xxxx.com mon. Util. MonitorLogger. WARN (27) Found timeout thread notify-replay-consumer...Copy the code

In this case, the link ID is not recorded because the thread is thread-monitor-daemon. The naming conventions for threads are also constrained at system design time

I’m not going to go into all the details and we’ll talk about it later.

The following example records the requested link ID

776 19006989 2021-08-04 22:35:25. [HTTP - nio - 0.0.0.0-8010 - exec - 10] [1 fc8pebmgwukw863w2p342rp2936a3r157w0:0:] the INFO Com. XXX. Framework. Eureka. Core. The listener. EurekaStateChangeListener. Listen (58) - service instances [XX - PAAS] registration is successful, the current server registered service instance number [3]Copy the code

For the system startup time, current time, current thread, and corresponding path shown in the figure above, log information can be gradually improved according to the official logBack configuration. However, special processing is required for the generation and writing of link ids.

Link ID Design

I personally prefer two options for link tracking design

The first kind of

In each request, the link number (traceId) and spanId (spanId) are transmitted through HttpHeader. The start position of the log automatically generates traceId and spanId, while the Parent spanId of the start position does not exist and is null.

In this way, every time the restTemplate and Openfeign interfaces of other services are accessed, the traceId and spanId generated at the start location are carried to the next service unit.

The second,

In each request the link number (traceId) is increased by 1 for depth without a microservice

public static class ThreadTraceListener implements ThreadListener { @Override public void onThreadBegin(HttpServletRequest request) { String traceToken = ThreadLocalUtil.getTranVar(TRACE_ID); String fromServer = ThreadLocalUtil.getTranVar(FROM_SERVER); int deep; String traceId; if (StringUtils.isBlank(traceToken)) { traceId = IDGenerator.generateID(); deep = 0; traceToken = StringHelper.join(traceId, ":0"); } else { int index = traceToken.lastIndexOf(':'); traceId = traceToken.substring(0, index); deep = Integer.valueOf(traceToken.substring(index + 1)); } ThreadLocalUtil.setLocalVar(TRACE_ID, traceId); ThreadLocalUtil.setLocalVar(TRACE_DEEP, deep); ThreadLocalUtil.setTranVar(TRACE_ID, StringHelper.join(traceId, ":", deep + 1)); ThreadLocalUtil.setLocalVar(FROM_SERVER, fromServer); ThreadLocalUtil.setTranVar(FROM_SERVER, getCurrentServer()); MDC.put(TRACE_ID, StringHelper.join(traceToken, ":", fromServer)); } @Override public void onThreadEnd(HttpServletRequest request) { MDC.remove(TRACE_ID); }}Copy the code

Request to intercept

protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain chain) throws ServletException, IOException { long startTime = System.currentTimeMillis(); TranVar = new HashMap<String, Object>(); Enumeration<String> headers = request.getHeaderNames(); while (headers.hasMoreElements()) { String key = headers.nextElement(); if (! StringUtils.isEmpty(key) && key.startsWith(ThreadLocalUtil.TRAN_PREFIX)) { tranVar.put(key.substring(ThreadLocalUtil.TRAN_PREFIX.length()), request.getHeader(key)); } } ThreadLocalHolder.begin(tranVar, request); try { if (isGateway) { response.addHeader("X-TRACE-ID", TraceUtil.getTraceId()); } // Check the RPC call depth checkRpcDeep(request, response); // Chain. DoFilter (request, response); // Record the number of RPC calls logRpcCount(request, response); } catch (Throwable ex) {Response<? > result = ExceptionUtil.toResponse(ex); Determine determine = ExceptionUtil.determineType(ex); ExceptionUtil.doLog(result, determine.getStatus(), ex); response.setStatus(determine.getStatus().value()); response.setCharacterEncoding("UTF-8"); response.setContentType(MediaType.APPLICATION_JSON_UTF8_VALUE); response.getWriter().write(JsonUtil.toJsonString(result)); } finally { try { doMonitor(request, response, startTime); if (TraceUtil.isTraceLoggerOn()) { log.warn(StringHelper.join( "TRACE-HTTP-", request.getMethod(), " URI:", request.getRequestURI(), ", dt:", System.currentTimeMillis() - startTime, ", rpc:", TraceUtil.getRpcCount(), ", status:", response.getStatus())); } else if (log.isTraceEnabled()) { log.trace(StringHelper.join(request.getMethod(), " URI:", request.getRequestURI(), ", dt:", System.currentTimeMillis() - startTime, ", rpc:", TraceUtil.getRpcCount(), ", status:", response.getStatus()));  } } finally { ThreadLocalHolder.end(request); }}}Copy the code

Click to follow, the first time to learn about Huawei cloud fresh technology ~