request的全鏈路追蹤（翻譯自官網）
MDC全稱Mapped Diagnostic Context，翻譯為上下文資訊診斷對映。為了追蹤不同客戶端對服務端的請求，並記錄他們的日誌呼叫資訊。一個簡單的做法就是為每個提供服務的客戶端請求單獨的記錄日誌資訊。LOGBACK利用了一系列這個技術應用到SLF4J API，形成了MDC。
為了單獨的記錄每一條請求，使用者需要將上下文資訊記錄到MDC中。MDC的類中僅僅包含了幾個靜態方法，它使得開發者可以將資訊放到上下文中，然後隨後可以被logback的相關元件檢索到。MDC基於每個執行緒去管理上下文資訊。典型地，當開始服務一個新的客戶端請求時，開發者將插入相關的上下文資訊，比如clientID，clientIP和相關引數等。logback如果做了相關的配置，那麼將在日誌體裡面自動包含所有這些資訊。
請注意，根據logback-classic實現的MDC，值會以中等的頻率放置到MDC中。另外一個子執行緒不回繼承父執行緒的引數值。
-
高階用法
MDC技術被廣泛的用在客戶端和服務端的架構中。典型的就是多個客戶端請求將由多個服務端執行緒去提供服務，儘管MDC提供的方法都是靜態的，但是每個上下文資訊是基於執行緒控制的，這就允許每個服務執行緒有明顯的MDC標記。MDC的諸如get和put操作影響的僅僅是當前執行緒和它的子執行緒。因此沒有必要擔心MDC在程式設計過程中的執行緒安全問題（猜測應該和ThreadLocal有關）。
下面的例子是更加高階的用法，它展示了MDC怎樣被應用在客戶端服務端模配置中。服務端實現了NumberCruncher介面，這個介面有唯一的方法factor（）。使用RMI技術，客戶端觸發服務端的這個方法檢索不同的整型因子。
interface介面：
package chapters.mdc; import java.rmi.Remote; import java.rmi.RemoteException; /** * NumberCruncher factors positive integers. */ public interface NumberCruncher extends Remote { /** * Factor a positive integer number and return its * distinct factor's as an integer array. * */ int[] factor(int number) throws RemoteException; }
服務端程式碼：
View Javadoc
1 /**
2 * Logback: the reliable, generic, fast and flexible logging framework.
3 * Copyright (C) 1999-2015, QOS.ch. All rights reserved.
4 *
5 * This program and the accompanying materials are dual-licensed under
6 * either the terms of the Eclipse Public License v1.0 as published by
7 * the Eclipse Foundation
8 *
9 * or (per the licensee's choosing)
10 *
11 * under the terms of the GNU Lesser General Public License version 2.1
12 * as published by the Free Software Foundation.
13 */
14 package chapters.mdc;
15
16 import java.rmi.RemoteException;
17 import java.rmi.registry.LocateRegistry;
18 import java.rmi.registry.Registry;
19 import java.rmi.server.UnicastRemoteObject;
20 import java.util.Vector;
21
22 import org.slf4j.Logger;
23 import org.slf4j.LoggerFactory;
24 import org.slf4j.MDC;
25
26 import ch.qos.logback.classic.LoggerContext;
27 import ch.qos.logback.classic.joran.JoranConfigurator;
28 import ch.qos.logback.core.joran.spi.JoranException;
29
30 /**
31 * A simple NumberCruncher implementation that logs its progress when
32 * factoring numbers. The purpose of the whole exercise is to show the
33 * use of mapped diagnostic contexts in order to distinguish the log
34 * output from different client requests.
35 * */
36 public class NumberCruncherServer extends UnicastRemoteObject implements NumberCruncher {
37
38 private static final long serialVersionUID = 1L;
39
40 static Logger logger = LoggerFactory.getLogger(NumberCruncherServer.class);
41
42 public NumberCruncherServer() throws RemoteException {
43 }
44
45 public int[] factor(int number) throws RemoteException {
46 // The client's host is an important source of information.
47 try {
48 MDC.put("client", NumberCruncherServer.getClientHost());
49 } catch (java.rmi.server.ServerNotActiveException e) {
50 logger.warn("Caught unexpected ServerNotActiveException.", e);
51 }
52
53 // The information contained within the request is another source
54 // of distinctive information. It might reveal the users name,
55 // date of request, request ID etc. In servlet type environments,
56 // useful information is contained in the HttpRequest or in the
57 // HttpSession.
58 MDC.put("number", String.valueOf(number));
59
60 logger.info("Beginning to factor.");
61
62 if (number <= 0) {
63 throw new IllegalArgumentException(number + " is not a positive integer.");
64 } else if (number == 1) {
65 return new int[] { 1 };
66 }
67
68 Vector<Integer> factors = new Vector<Integer>();
69 int n = number;
70
71 for (int i = 2; (i <= n) && ((i * i) <= number); i++) {
72 // It is bad practice to place log requests within tight loops.
73 // It is done here to show interleaved log output from
74 // different requests.
75 logger.debug("Trying " + i + " as a factor.");
76
77 if ((n % i) == 0) {
78 logger.info("Found factor " + i);
79 factors.addElement(i);
80
81 do {
82 n /= i;
83 } while ((n % i) == 0);
84 }
85
86 // Placing artificial delays in tight loops will also lead to
87 // sub-optimal resuts. :-)
88 delay(100);
89 }
90
91 if (n != 1) {
92 logger.info("Found factor " + n);
93 factors.addElement(n);
94 }
95
96 int len = factors.size();
97
98 int[] result = new int[len];
99
100 for (int i = 0; i < len; i++) {
101 result[i] = ((Integer) factors.elementAt(i)).intValue();
102 }
103
104 // clean up
105 MDC.remove("client");
106 MDC.remove("number");
107
108 return result;
109 }
110
111 static void usage(String msg) {
112 System.err.println(msg);
113 System.err.println("Usage: java chapters.mdc.NumberCruncherServer configFile\n" + " where configFile is a logback configuration file.");
114 System.exit(1);
115 }
116
117 public static void delay(int millis) {
118 try {
119 Thread.sleep(millis);
120 } catch (InterruptedException e) {
121 }
122 }
123
124 public static void main(String[] args) {
125 if (args.length != 1) {
126 usage("Wrong number of arguments.");
127 }
128
129 String configFile = args[0];
130
131 if (configFile.endsWith(".xml")) {
132 try {
133 LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory();
134 JoranConfigurator configurator = new JoranConfigurator();
135 configurator.setContext(lc);
136 lc.reset();
137 configurator.doConfigure(args[0]);
138 } catch (JoranException je) {
139 je.printStackTrace();
140 }
141 }
142
143 NumberCruncherServer ncs;
144
145 try {
146 ncs = new NumberCruncherServer();
147 logger.info("Creating registry.");
148
149 Registry registry = LocateRegistry.createRegistry(Registry.REGISTRY_PORT);
150 registry.rebind("Factor", ncs);
151 logger.info("NumberCruncherServer bound and ready.");
152 } catch (Exception e) {
153 logger.error("Could not bind NumberCruncherServer.", e);
154
155 return;
156 }
157 }
158 }
Copyright © 2005–2018 QOS.ch. All rights reserved.factor方法的實現是相關的。初始時將客戶端的主機地址放到MDC中。當客戶端請求時，factor的值被放到MDC中。當計算出這個整型引數不同的因子後，將結果返回給客戶端。在返回結果之前，MDC中的值被清空。正常情況下，put操作應該對應相關的remove 操作。因此，這個MDC中的鍵應該包含穩定的值。因此建議將remove操作放置到finally塊中以保證被執行。
下面是XML的配置：
<configuration>
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<layout>
<Pattern>%-4r [%thread] %-5level C:%X{client} N:%X{number} - %msg%n</Pattern>
</layout>
</appender>
<root level="debug">
<appender-ref ref="CONSOLE"/>
</root>
</configuration>The attentive reader might have observed that the thread name could also have been used to distinguish each request. The thread name can cause confusion if the server side technology recycles threads. In that case, it may be hard to determine the boundaries of each request, that is, when a given thread finishes servicing a request and when it begins servicing the next. Because the MDC is under the control of the application developer, MDC stamps do not suffer from this problem.
細心的讀者可能發現執行緒名也可以被用來區分不同的請求。但是當服務端迴圈利用執行緒時就會出現問題，比如使用執行緒池技術。這種情況下，就很難區分每個請求。因為這個MDC是在應用開發者的控制下，所以MDC的stamp不會遇到這個問題。
-
自動操作MDC
就像我們上面看到的那樣，MDC在處理多客戶端請求的時候是非常有用的。在web應用管理客戶認證的場景下，一個簡單的解決方案就是將使用者的使用者名稱放到MDC中讓後在使用者登出的時候移除它。不幸的是，使用這個技術並不總是可以獲得準確的值。既然MDC是基於執行緒儲存值的，那麼當一個服務端迴圈利用這個執行緒時可能會導致錯誤的資訊在MDC中。
為了允許任何時候處理請求時MDC中的資訊是正確的，一個可行的方案是在開始處理請求的時候就儲存使用者名稱，然後在處理完成的時候移除它。這種情況下filter就派上用場了。在filter的doFilter方法中，我們可以檢索相關的使用者資訊通過request並且將他們儲存在MDC中。接下來的filter將自動的可以獲取到先前儲存的MDC的資料。最後，當我們的filter恢復控制的時候（也就是呼叫鏈返回處理的時候）我們可以清除MDC中的資訊。
下面是例子：
package chapters.mdc;
import java.io.IOException;
import java.security.Principal;
import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpSession;
import org.slf4j.MDC;
public class UserServletFilter implements Filter {
private final String USER_KEY = "username";
public void destroy() {
}
public void doFilter(ServletRequest request, ServletResponse response,
FilterChain chain) throws IOException, ServletException {
boolean successfulRegistration = false;
HttpServletRequest req = (HttpServletRequest) request;
Principal principal = req.getUserPrincipal();
// Please note that we could have also used a cookie to
// retrieve the user name
if (principal != null) {
String username = principal.getName();
successfulRegistration = registerUsername(username);
}
try {
chain.doFilter(request, response);
} finally {
if (successfulRegistration) {
MDC.remove(USER_KEY);
}
}
}
public void init(FilterConfig arg0) throws ServletException {
}
/**
* Register the user in the MDC under USER_KEY.
*
* @param username
* @return true id the user can be successfully registered
*/
private boolean registerUsername(String username) {
if (username != null && username.trim().length() > 0) {
MDC.put(USER_KEY, username);
return true;
}
return false;
}
}當執行doFilter方法時，首先會在request中查詢java.security.Principal物件。這個物件包含了當前認證使用者的使用者名稱，如果查詢到一個使用者的資訊，那麼使用者名稱被放置到MDC中。一旦filter呼叫鏈執行完畢，filter就會移除MDC中的使用者資訊。這個方法中，我們僅僅為持久化請求和處理這個請求的執行緒設定MDC的值。其他的執行緒是不受影響的，在任何時間點，給定的執行緒將會持有正確的值。
-
MDC和管理執行緒
一個MDC上線文資訊不會總是被來自初始化執行緒的工作執行緒繼承。這種情況就是執行緒池的使用。在這種情況下，意味著MDC.getCopyOfContextMap()操作要在提交一個任務到executor之前被執行。當任務啟動的時候，首先應該呼叫MDC. setcontextmapvalues()方法來將原始MDC值的儲存副本與新的執行器託管執行緒關聯起來。
在web應用中，常常會提供有用的資訊，比如和給定的request相關的hostname/request Uri/user-agent等資訊。
| MDC key | MDC value |
|---|---|
req.remoteHost |
|
req.xForwardedFor |
|
req.method |
as returned by getMethod() method |
req.requestURI |
|
req.requestURL |
|
req.queryString |
|
req.userAgent |
value of the "User-Agent" header |
web的XML檔案配置：
<filter>
<filter-name>MDCInsertingServletFilter</filter-name>
<filter-class>
ch.qos.logback.classic.helpers.MDCInsertingServletFilter
</filter-class>
</filter>
<filter-mapping>
<filter-name>MDCInsertingServletFilter</filter-name>
<url-pattern>/*</url-pattern>
</filter-mapping> 如果你的web應用有多個過濾器，那麼確保該過濾器在所有過濾器之前被宣告。一旦安裝了過濾器，每個MDC鍵對應的值將由%X轉換字根據金鑰傳遞作為首選項輸出。例如，要在一行上列印遠端主機後面跟著請求URI，在另一行上列印日期後面跟著訊息，您可以將PatternLayout的模式設定為:%X{req.remoteHost} %X{req.requestURI}%n%d - %m%n。
-
寫在最後
本文翻譯自logBack官網，主要介紹了請求間的值傳遞問題，對於呼叫鏈的開發來說是一個基礎思想，翻譯的不好，還請大家見諒，歡迎留言交流。