Практика межпотокового отслеживания журналов журналов
Когда наша программа работает на сервере, часто ли трудно найти проблему?Когда вам выдают много сложных файлов журнала, как вы можете найти проблему? Исходный код этого проекта выложен на Github:GitHub.com/Лю Шуньцю/…
1. Настройте параметры шаблона журнала: Шаблон Logback's Pattern
Когда приходит запрос, мы хотим знать, какой процесс запустил текущий запрос, как это сделать? Deng Deng Deng Deng.. Скоро появится наш шаблон пользовательского шаблона Logback для мужчин.
Когда мы печатаем лог, мы обычно записываем в лог какую-то важную информацию о параметрах, что нам удобно, чтобы потом найти проблему из лога.Когда другие внутренние системы вызывают нашу программу, мы можем попросить их поместить заголовок в шапку В него добавляется уникальный идентификатор типа trace-id.Если такого параметра нет, то мы вручную генерируем уникальный идентификатор, который нам удобен для построения всей ссылки запроса.
<property name="CONSOLE_LOG_PATTERN"
value="[%yellow(%date{yyyy-MM-dd HH:mm:ss})] [%highlight(%-5level)] [%cyan(%traceId)] [%magenta(%thread)] [%blue(%file:%line)] [%green(%logger)] : %.4000m%n"/>
Вот переменная определения Logback, сосредоточьтесь на[%cyan(%traceId)]Этот параметр (ps: другие системы ведения журнала, такие как log4j2, имеют аналогичные реализации)
Чтобы Logback распознал наш пользовательский идентификатор, нам нужно наследовать два методаClassicConverterа такжеPatternLayout, конкретная реализация выглядит следующим образом:
public class PatternLogbackLayout extends PatternLayout {
static {
defaultConverterMap.put("traceId", TraceIdPatternConverter.class.getName());
}
}
public class TraceIdPatternConverter extends ClassicConverter {
@Override
public String convert(ILoggingEvent iLoggingEvent) {
String traceId = LogHandlerInterceptor.getTrack();
return StringUtils.isEmpty(traceId) ? "traceId" : traceId;
}
}
Через перехватчик Spring мы назначаем параметры в заголовке заголовка запроса для traceId, а затем настраиваем logback.xml, чтобы logback распознавал определенный нами traceId.
<appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
<encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
<layout class="com.blacksearch.logback.PatternLogbackLayout">
<pattern>${CONSOLE_LOG_PATTERN}</pattern>
</layout>
</encoder>
</appender>
Через приведенную выше конфигурацию мы уже можем увидеть журнал внутри TraceID
[2019-05-10 16:47:38] [INFO ] [538e2c0d-3800-4c86-b320-260bdd945c0c] [http-nio-8080-exec-6] [TestLogTrackController.java:15] [com.blacksearch.controller.TestLogTrackController] : 测试
[2019-05-10 16:47:38] [DEBUG] [538e2c0d-3800-4c86-b320-260bdd945c0c] [http-nio-8080-exec-6] [AbstractMessageConverterMethodProcessor.java:298] [org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor] : Nothing to write: null body
Таким образом, на сервере мы можем пройти
grep '538e2c0d-3800-4c86-b320-260bdd945c0c'
Просмотрите все журналы текущего запроса~ или выполните прямой поиск 538e2c0d-3800-4c86-b320-260bdd945c0c после того, как ELK удобен и счастлив~
2. Когда мы используем многопоточность, мы обнаружили, что изначально определенный логотип исчез! ! !
Решение. Пользовательский абстрактный класс реализует Runnable. Во-первых, давайте воспроизведем проблему, например:
@RequestMapping("/asynLogTrack")
public String asynLogTrack(){
logger.info("ces--------");
new Thread(new Runnable() {
@Override
public void run() {
logger.info("ces");
}
}).start();
return null;
}
[2019-05-10 16:55:18] [INFO ] [5b446567-97be-42f7-b6b0-205a6b431e87] [http-nio-8080-exec-2] [TestLogTrackController.java:21] [com.blacksearch.controller.TestLogTrackController] : ces--------
[2019-05-10 16:55:18] [INFO ] [traceId] [Thread-10] [TestLogTrackController.java:25] [com.blacksearch.controller.TestLogTrackController] : ces
[2019-05-10 16:55:18] [DEBUG] [5b446567-97be-42f7-b6b0-205a6b431e87] [http-nio-8080-exec-2] [AbstractMessageConverterMethodProcessor.java:298] [org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor] : Nothing to write: null body
Мы увидели запись о печати ces и обнаружили, что traceId на самом деле был утерян!!! Причина в том, что стек является частным для потока.Когда мы создаем новый поток, новый поток не зависит от исходного потока, а это означает, что журнал не может получить значение во вновь созданном потоке. В этом случае, как мы можем заставить Logback получить значение в новом потоке? Как следует из названия.
public abstract class TrackRunnable implements Runnable {
public abstract void trackRun();
private String track = LogHandlerInterceptor.getTrack();
@Override
public void run() {
try {
LogHandlerInterceptor.setTrace(track);
trackRun();
}finally {
LogHandlerInterceptor.remove();
}
}
}
Мы используем абстрактные классы для реализацииRunnable, затем вrun()Метод переназначается через ThreadLocal. например:
@RequestMapping("/asynLogTrackHasTrace")
public String asynLogTrackHasTrace(){
logger.info("ces1------");
new Thread(new TrackRunnable() {
@Override
public void trackRun() {
try {
Thread.sleep(4000);
} catch (InterruptedException e) {
e.printStackTrace();
}
logger.info("ces2-----------");
}
}).start();
return null;
}
[2019-05-10 17:07:20] [INFO ] [0a7f30d3-8e1d-49b4-9bca-4b72fd1c0ccd] [http-nio-8080-exec-5] [TestLogTrackController.java:33] [com.blacksearch.controller.TestLogTrackController] : ces1------
[2019-05-10 17:07:20] [DEBUG] [0a7f30d3-8e1d-49b4-9bca-4b72fd1c0ccd] [http-nio-8080-exec-5] [AbstractMessageConverterMethodProcessor.java:298] [org.springframework.web.servlet.mvc.method.annotation.RequestResponseBodyMethodProcessor] : Nothing to write: null body
[2019-05-10 17:07:20] [DEBUG] [traceId] [http-nio-8080-exec-5] [FrameworkServlet.java:1130] [org.springframework.web.servlet.DispatcherServlet] : Completed 200 OK
[2019-05-10 17:07:24] [INFO ] [0a7f30d3-8e1d-49b4-9bca-4b72fd1c0ccd] [Thread-11] [TestLogTrackController.java:42] [com.blacksearch.controller.TestLogTrackController] : ces2-----------
Идеальное решение проблемы~ Приведенный выше код был загружен на сайт однополых знакомств~ Добро пожаловать, чтобы посмотреть, как чиновники делают кирпич~