Java 로그 수준, 중복 기록, 로그 손실 문제 이해
- coldplay.xixi앞으로
- 2020-12-11 17:26:349682검색
Java 기본 튜토리얼이 칼럼에서는 Java 로그 수준과 같은 문제를 해결하는 방법을 소개합니다
관련 무료 학습 권장 사항: Java Basic Tutorial
1 로그 오류의 일반적인 원인
1.1 로깅이 많습니다. 프레임워크
다른 클래스 라이브러리 다른 로그 프레임워크가 사용될 수 있으며 호환성이 문제입니다
1.2 구성이 복잡하고 오류가 발생하기 쉽습니다
로그 구성 파일은 일반적으로 다른 프레임워크에서 직접 구성 파일을 복사하는 데 익숙합니다. 프로젝트나 온라인 블로그를 수정하지만 수정하는 방법을 주의 깊게 연구하지 마세요. 일반적인 오류는 중복 로깅, 동기 로깅 성능 및 비동기 로깅 구성 오류에서 발생합니다.
1.3 로깅 자체에 오해가 있는 부분이 있습니다
예를 들어 로그 콘텐츠 획득 비용을 고려하지 않은 경우, 로그 수준을 임의로 사용하는 경우 등이 있습니다.
2 SLF4J
JDK와 함께 제공되는 Logback, Log4j, Log4j2, commons-logging, java.util.logging 등은 모두 Java 시스템의 로깅 프레임워크이며 실제로 많이 있습니다. 다양한 클래스 라이브러리는 다양한 로깅 프레임워크를 사용하도록 선택할 수도 있습니다. 결과적으로 로그의 통합 관리가 매우 어려워집니다.
- SLF4J(Simple Logging Facade For Java)는 이 문제를 해결하기 위해 통합된 로깅 Facade API를 제공합니다
- 그림에서 보라색 부분은 중립 로깅 API
- 브리징 기능인 파란색 부분은 다양한 로그 프레임워크 API(녹색 부분)를 SLF4J API에 연결합니다. 이런 방식으로 다양한 로깅 API를 사용하여 프로그램에 로그를 기록하더라도 결국에는 SLF4J Facade API에 브리지할 수 있습니다.
- 빨간 부분인 적응 기능은 SLF4J API와 실제 로그 프레임워크(회색 부분)의 바인딩을 실현할 수 있습니다.
SLF4J는 단지 로깅 표준인가요? 실제 로깅 프레임워크가 여전히 필요합니까? 로깅 프레임워크 자체는 SLF4J API를 구현하지 않으므로 사전 변환이 필요합니다. Logback은 SLF4J API 표준에 따라 구현되므로 변환을 위해 모듈을 바인딩할 필요가 없습니다.
log4j-over-slf4j를 사용하여 Log4j를 SLF4J에 연결할 수 있지만 slf4j-log4j12를 사용하여 SLF4J를 Log4j에 적용하고 한 열에 그릴 수도 있습니다. . 그러나 동시에 사용할 수는 없으며, 그렇지 않으면 무한 루프가 발생합니다. jcl과 jul도 마찬가지입니다. log4j-over-slf4j实现Log4j桥接到SLF4J，也可使用slf4j-log4j12实现SLF4J适配到Log4j，也把它们画到了一列，但是它不能同时使用它们，否则就会产生死循环。jcl和jul同理。
虽然图中有4个灰色的日志实现框架，但日常业务使用最多的还是Logback和Log4j，都是同一人开发的。Logback可认为是Log4j改进版，更推荐使用，基本已是主流。
Spring Boot的日志框架也是Logback。那为什么我们没有手动引入Logback包，就可直接使用Logback？
spring-boot-starter模块依赖spring-boot-starter-logging模块
spring-boot-starter-logging模块自动引入logback-classic（包含SLF4J和Logback日志框架）和SLF4J的一些适配器。其中，log4j-to-slf4j用于实现Log4j2 API到SLF4J的桥接，jul-to-slf4j则是实现java.util.logging API到SLF4J的桥接。
3 日志重复记录
日志重复记录不但给查看日志和统计工作带来不必要的麻烦，还会增加磁盘和日志收集系统的负担。
logger配置继承关系导致日志重复记录
定义一个方法实现debug、info、warn和error四种日志的记录
Logback配置
配置看没啥问题，执行方法后出现日志重复记录
分析
CONSOLE这个Appender同时挂载到了俩Logger，定义的<logger>和<root>，由于定义的<logger>继承自<root>，所以同一条日志既会通过logger记录，也会发送到root记录，因此应用package下日志出现重复记录。
如此配置的初衷是啥呢？
内心是想实现自定义logger配置，让应用内的日志暂时开启DEBUG级别日志记录。其实，这无需重复挂载Appender，去掉<logger>下挂载的Appender即可：
<logger name="org.javaedge.time.commonmistakes.logging" level="DEBUG"/>
若自定义<logger>需把日志输出到不同Appender：
比如
- 应用日志输出到文件app.log
- 其他框架日志输出到控制台
可设置<logger>的additivity属性为false，这就不会继承<root>
그림에는 4개의 회색 로그 구현 프레임워크가 있지만 일상 업무에서 가장 많이 사용되는 프레임워크는 Logback과 Log4j이며 둘 다 같은 사람이 개발했습니다. Logback은 Log4j의 개선된 버전으로 간주될 수 있으며 이는 더 권장되며 기본적으로 주류입니다. 
🎜🎜🎜🎜로그백 구성🎜
🎜🎜🎜🎜구성에는 아무런 문제가 없지만 메소드 실행 후 중복된 로그 기록이 나타납니다🎜
🎜🎜🎜🎜Analytic🎜 CONSOLE 이 Appender는 두 개의 Logger에 동시에 마운트되며, 정의된 <logger> 및 <root>, 정의된 <logger>는 <root>에서 상속되므로 동일한 로그는 다음과 같습니다. 로거에 의해 기록되고 루트에 Record를 보냈기 때문에 애플리케이션 패키지 아래의 로그에 중복된 기록이 있습니다. 🎜🎜🎜🎜이 구성의 원래 의도는 무엇입니까? 🎜 마음속으로는 애플리케이션의 로그가 일시적으로 DEBUG 수준의 로깅을 활성화할 수 있도록 커스텀 로거 구성을 구현하고 싶습니다. 실제로 Appender를 반복적으로 마운트할 필요가 없으며 <logger> 아래에 마운트된 Appender를 제거하기만 하면 됩니다. 🎜public class AsyncAppender extends AsyncAppenderBase<ILoggingEvent> {
// 是否收集调用方数据
boolean includeCallerData = false;
protected boolean isDiscardable(ILoggingEvent event) {
Level level = event.getLevel();
// 丢弃 ≤ INFO级日志
return level.toInt() <= Level.INFO_INT;
}
protected void preprocess(ILoggingEvent eventObject) {
eventObject.prepareForDeferredProcessing();
if (includeCallerData)
eventObject.getCallerData();
}}public class AsyncAppenderBase<E> extends UnsynchronizedAppenderBase<E> implements AppenderAttachable<E> {
// 阻塞队列：实现异步日志的核心
BlockingQueue<E> blockingQueue;
// 默认队列大小
public static final int DEFAULT_QUEUE_SIZE = 256;
int queueSize = DEFAULT_QUEUE_SIZE;
static final int UNDEFINED = -1;
int discardingThreshold = UNDEFINED;
// 当队列满时：加入数据时是否直接丢弃，不会阻塞等待
boolean neverBlock = false;
@Override
public void start() {
...
blockingQueue = new ArrayBlockingQueue<E>(queueSize);
if (discardingThreshold == UNDEFINED)
//默认丢弃阈值是队列剩余量低于队列长度的20%，参见isQueueBelowDiscardingThreshold方法
discardingThreshold = queueSize / 5;
...
}
@Override
protected void append(E eventObject) {
if (isQueueBelowDiscardingThreshold() && isDiscardable(eventObject)) { //判断是否可以丢数据
return;
}
preprocess(eventObject);
put(eventObject);
}
private boolean isQueueBelowDiscardingThreshold() {
return (blockingQueue.remainingCapacity() < discardingThreshold);
}
private void put(E eventObject) {
if (neverBlock) { //根据neverBlock决定使用不阻塞的offer还是阻塞的put方法
blockingQueue.offer(eventObject);
} else {
putUninterruptibly(eventObject);
}
}
//以阻塞方式添加数据到队列
private void putUninterruptibly(E eventObject) {
boolean interrupted = false;
try {
while (true) {
try {
blockingQueue.put(eventObject);
break;
} catch (InterruptedException e) {
interrupted = true;
}
}
} finally {
if (interrupted) {
Thread.currentThread().interrupt();
}
}
}}🎜<logger>를 사용자 정의하고 필요한 경우 로그를 출력하려면 다른 어펜더에: 🎜 예를 들어 🎜🎜🎜 애플리케이션 로그는 app.log 파일로 출력됩니다.🎜🎜다른 프레임워크 로그는 콘솔로 출력됩니다🎜🎜🎜 <logger> >속성은 false이며 <root>🎜🎜🎜의 Appender를 상속하지 않습니다.레벨 필터를 잘못 구성하면 로그가 중복됩니다
콘솔에 로그를 기록하는 동안 로그 기록은 서로 다른 레벨에 따라 두 개의 파일에 기록됩니다.
실행 결과
info.log 파일에는 INFO, WARN이 포함됩니다. 예상과 다른 ERROR 3레벨 로그
error.log에는 WARN 및 ERROR 레벨 로그가 포함되어 반복적으로 로그가 수집됩니다
Accident Accountability
일부 회사에서는 자동화된 ELK 솔루션을 사용하여 로그를 수집합니다. 그리고 로그는 동시에 수집되어 콘솔과 파일로 출력됩니다. 개발자는 로컬에서 테스트할 때 파일에 기록된 로그에 신경 쓰지 않습니다. 테스트 및 프로덕션 환경에서는 개발자에게 서버 액세스 권한이 없기 때문에 문제가 반복됩니다. 원본 로그 파일에서는 찾기가 어렵습니다.
로그가 반복되는 이유는 무엇인가요?
ThresholdFilter 소스 코드 분석
-
로그 수준 ≥ 구성 수준이 日志级别 ≥ 配置级别 返回NEUTRAL，继续调用过滤器链上的下个过滤器
- 否则返回DENY，直接拒绝记录日志
该案例我们将 ThresholdFilter 置 WARN，因此可记录WARN和ERROR级日志。
LevelFilter
用于比较日志级别，然后进行相应处理。
- 若匹配就调用onMatch定义的处理方式：默认交给下一个过滤器处理（AbstractMatcherFilter基类中定义的默认值）
- 否则调用onMismatch定义的处理方式：默认也是交给下一个过滤器
和ThresholdFilter不同，LevelFilter仅配置level无法真正起作用。
由于未配置onMatch和onMismatch属性，所以该过滤器失效，导致INFO以上级别日志都记录了。
修正
配置LevelFilter的onMatch属性为ACCEPT，表示接收INFO级别的日志；配置onMismatch属性为DENY，表示除了INFO级别都不记录：
如此，_info.logNEUTRAL
을 반환하고 필터 체인의 다음 필터를 계속 호출하는 경우 그렇지 않으면 DENY
를 반환하고 직접 기록을 거부합니다. logs
이 경우에는
ThresholdFilter를 설정합니다. 
~
WARN
이므로 WARN 및 ERROR 레벨 로그가 기록될 수 있습니다.
LevelFilter- 는 로그 수준을 비교한 다음 그에 따라 처리하는 데 사용됩니다.
일치하는 것이 있으면 onMatch를 호출합니다.
정의된 처리 방법: 기본적으로 다음 필터(AbstractMatcherFilter 기본 클래스에 정의된 기본값)로 넘겨집니다. 
그렇지 않으면
onMismatch가 호출됩니다. 정의된 처리 방법: 기본적으로 다음 필터에도 넘겨집니다. 필터
는
ThresholdFilter
, 
LevelFilter
레벨 구성만으로는 실제로 작동할 수 없습니다와 다릅니다. 🎜🎜onMatch 및 onMismatch 속성이 구성되지 않았으므로 필터가 실패하여 INFO보다 높은 수준의 로그가 기록됩니다. 🎜🎜Correction🎜🎜 LevelFilter의 onMatch 속성을 ACCEPT로 구성합니다. 이는 INFO 수준 로그 수신을 의미합니다. onMismatch 속성을 DENY로 구성합니다. 이는 INFO 수준 외에는 레코드가 없음을 의미합니다. 🎜
🎜🎜이런 방식으로 _info.log 파일에는 INFO 수준 로그만 포함되며, 중복된 로그는 없습니다. 🎜🎜4 비동기 로깅이 성능을 향상합니까?🎜🎜로그를 파일에 올바르게 출력하는 방법을 알고 나면 로깅이 시스템 성능 병목 현상을 일으키지 않도록 방지하는 방법을 고려해야 합니다. 이를 통해 디스크(예: 기계식 디스크)의 IO 성능이 좋지 않고 로그 볼륨이 큰 경우 로그를 어떻게 기록해야 하는지에 대한 문제를 해결할 수 있습니다. 🎜🎜다음 로그 구성을 정의합니다. 총 2개의 Appender가 있습니다. 🎜🎜FILE은 모든 로그를 기록하는 데 사용되는 FileAppender입니다. 🎜 CONSOLE은 시간 표시와 함께 로그를 기록하는 데 사용되는 ConsoleAppender입니다. 🎜🎜🎜 많은 양의 로그를 파일로 출력하면 로그 파일의 크기가 매우 커집니다. 성능 테스트 결과도 섞여 있으면 해당 로그를 찾기가 어렵습니다. 따라서 여기서는 EvaluatorFilter를 사용하여 태그에 따라 로그를 필터링하고, 필터링된 로그는 별도로 콘솔에 출력됩니다. 이 경우 테스트 결과를 출력하는 로그에 시간 표시가 추가됩니다. 🎜🎜🎜🎜태그와 EvaluatorFilter를 함께 사용하여 태그별로 로그를 필터링하세요🎜. 🎜🎜🎜🎜테스트 코드: 지정된 횟수만큼 큰 로그를 기록합니다. 각 로그에는 1MB의 시뮬레이션 데이터가 포함됩니다. 마지막으로 시간으로 표시된 메소드 실행 시간이 많이 걸리는 로그가 기록됩니다. 프로그램 실행 후, 1000개 로그와 10000개 로그를 기록하는 호출 시간은 각각 5.1초, 39초입니다🎜🎜🎜🎜🎜파일 로그만 기록하는 코드의 경우 시간이 너무 오래 걸립니다. 🎜🎜소스 코드 분석🎜🎜FileAppender는 OutputStreamAppender에서 상속됩니다🎜🎜🎜 로그를 추가할 때 로그는 동기 로그 레코드인 OutputStream에 직접 기록됩니다🎜🎜🎜所以日志大量写入才会旷日持久。如何才能实现大量日志写入时，不会过多影响业务逻辑执行耗时而影响吞吐量呢？
AsyncAppender
使用Logback的AsyncAppender
即可实现异步日志记录。AsyncAppender类似装饰模式，在不改变类原有基本功能情况下为其增添新功能。这便可把AsyncAppender附加在其他Appender，将其变为异步。
定义一个异步Appender ASYNCFILE，包装之前的同步文件日志记录的FileAppender， 即可实现异步记录日志到文件
- 记录1000次日志和10000次日志的调用耗时，分别是537毫秒和1019毫秒
异步日志真的如此高性能？并不，因为这并没有记录下所有日志。
AsyncAppender异步日志坑
- 记录异步日志撑爆内存
- 记录异步日志出现日志丢失
- 记录异步日志出现阻塞。
案例
模拟慢日志记录场景：
首先，自定义一个继承自ConsoleAppender的MySlowAppender，作为记录到控制台的输出器，写入日志时休眠1秒。
配置文件中使用AsyncAppender，将MySlowAppender包装为异步日志记录
测试代码
耗时很短但出现日志丢失：要记录1000条日志，最终控制台只能搜索到215条日志，而且日志行号变问号。
原因分析
AsyncAppender提供了一些配置参数，而当前没用对。
源码解析
- includeCallerData
默认false：方法行号、方法名等信息不显示
- queueSize
控制阻塞队列大小，使用的ArrayBlockingQueue阻塞队列，默认容量256：内存中最多保存256条日志
- discardingThreshold
丢弃日志的阈值，为防止队列满后发生阻塞。默认队列剩余容量 ＜ 队列长度的20%，就会丢弃TRACE、DEBUG和INFO级日志
- neverBlock
控制队列满时，加入的数据是否直接丢弃，不会阻塞等待，默认是false
- 队列满时：offer不阻塞，而put会阻塞
- neverBlock为true时，使用offer
public class AsyncAppender extends AsyncAppenderBase<ILoggingEvent> {
// 是否收集调用方数据
boolean includeCallerData = false;
protected boolean isDiscardable(ILoggingEvent event) {
Level level = event.getLevel();
// 丢弃 ≤ INFO级日志
return level.toInt() <= Level.INFO_INT;
}
protected void preprocess(ILoggingEvent eventObject) {
eventObject.prepareForDeferredProcessing();
if (includeCallerData)
eventObject.getCallerData();
}}public class AsyncAppenderBase<E> extends UnsynchronizedAppenderBase<E> implements AppenderAttachable<E> {
// 阻塞队列：实现异步日志的核心
BlockingQueue<E> blockingQueue;
// 默认队列大小
public static final int DEFAULT_QUEUE_SIZE = 256;
int queueSize = DEFAULT_QUEUE_SIZE;
static final int UNDEFINED = -1;
int discardingThreshold = UNDEFINED;
// 当队列满时：加入数据时是否直接丢弃，不会阻塞等待
boolean neverBlock = false;
@Override
public void start() {
...
blockingQueue = new ArrayBlockingQueue<E>(queueSize);
if (discardingThreshold == UNDEFINED)
//默认丢弃阈值是队列剩余量低于队列长度的20%，参见isQueueBelowDiscardingThreshold方法
discardingThreshold = queueSize / 5;
...
}
@Override
protected void append(E eventObject) {
if (isQueueBelowDiscardingThreshold() && isDiscardable(eventObject)) { //判断是否可以丢数据
return;
}
preprocess(eventObject);
put(eventObject);
}
private boolean isQueueBelowDiscardingThreshold() {
return (blockingQueue.remainingCapacity() < discardingThreshold);
}
private void put(E eventObject) {
if (neverBlock) { //根据neverBlock决定使用不阻塞的offer还是阻塞的put方法
blockingQueue.offer(eventObject);
} else {
putUninterruptibly(eventObject);
}
}
//以阻塞方式添加数据到队列
private void putUninterruptibly(E eventObject) {
boolean interrupted = false;
try {
while (true) {
try {
blockingQueue.put(eventObject);
break;
} catch (InterruptedException e) {
interrupted = true;
}
}
} finally {
if (interrupted) {
Thread.currentThread().interrupt();
}
}
}}默认队列大小256，达到80%后开始丢弃<=INFO级日志后，即可理解日志中为什么只有两百多条INFO日志了。
queueSize 过大
可能导致OOM
queueSize 较小
默认值256就已经算很小了，且discardingThreshold设置为大于0（或为默认值），队列剩余容量少于discardingThreshold的配置就会丢弃<=INFO日志。这里的坑点有两个：
- 因为discardingThreshold，所以设置queueSize时容易踩坑。
比如本案例最大日志并发1000，即便置queueSize为1000，同样会导致日志丢失 - discardingThreshold参数容易有歧义，它
不是百分比，而是日志条数。对于总容量10000队列，若希望队列剩余容量少于1000时丢弃，需配置为1000
neverBlock 默认false
意味总可能会出现阻塞。
- 若discardingThreshold = 0，那么队列满时再有日志写入就会阻塞
- 若discardingThreshold != 0，也只丢弃≤INFO级日志，出现大量错误日志时，还是会阻塞
queueSize、discardingThreshold和neverBlock三参密不可分，务必按业务需求设置：
- 若优先绝对性能，设置
neverBlock = true，永不阻塞 - 若优先绝不丢数据，设置
discardingThreshold = 0，即使≤INFO级日志也不会丢。但最好把queueSize设置大一点，毕竟默认的queueSize显然太小，太容易阻塞。 - 若兼顾，可丢弃不重要日志，把queueSize设置大点，再设置合理的discardingThreshold
以上日志配置最常见两个误区
로그인 자체에 대한 오해를 살펴보겠습니다.
로그 자리 표시자를 사용하면 로그 수준을 판단할 필요가 없어지나요?
SLF4J의 {} 자리 표시자 구문은 로그가 실제로 기록될 때만 실제 매개변수를 가져오므로 로그 데이터 획득의 성능 문제를 해결합니다.
이게 맞나요?
- 인증코드: 결과를 반환하는데 1초가 걸립니다
DEBUG 로그를 기록하고 >=INFO 수준의 로그만 기록하도록 설정하면 프로그램도 1초가 걸리나요?
세 가지 테스트 방법:
- 문자열을 연결하여 SlowString을 기록합니다.
- 자리 표시자 방법을 사용하여 SlowString을 기록합니다.
- 먼저 로그 수준이 DEBUG를 활성화했는지 확인합니다.
처음 두 메서드는 모두 SlowString을 호출하므로 둘 다 1을 사용합니다. 두 번째 방법은 자리 표시자를 사용하여 SlowString을 기록하는 것입니다. 이 방법을 사용하면 String을 명시적으로 연결하지 않고도 Object를 전달할 수 있지만 이는 지연일 뿐입니다(로그가 기록되지 않으면 생략됩니다) Log 매개 변수 object.toString() 문자열 연결에 시간이 많이 걸립니다.
이 경우 로그 수준이 미리 결정되지 않은 이상 SlowString을 호출해야 합니다.
따라서 {}占位符을 사용하면 매개변수 값 획득이 지연되어 로그 데이터 획득의 성능 문제를 해결할 수 없습니다.
로그 수준을 미리 판단하는 것 외에도 람다 표현식을 통해 지연된 매개변수 내용을 얻을 수도 있습니다. 그러나 SLF4J의 API는 아직 람다를 지원하지 않으므로 Log4j2 로그 API를 사용하고 Lombok의 @Slf4j 주석을 **@Log4j2** 주석으로 바꿔서 람다 표현식 매개변수에 대한 메소드를 제공해야 합니다.
Call 이 디버그, 서명 Supplier와 같이 매개변수는 로그가 실제로 필요할 때까지 지연됩니다.
그래서 debug4는 SlowString 메소드를 호출하지 않습니다.
그냥 교체하세요. Log4j2 API를 사용하면 실제 로깅은 여전히 Logback을 통해 이루어집니다. 이것이 SLF4J 적응의 이점입니다.
Summary
- SLF4J는 Java 로깅 프레임워크를 통합합니다. SLF4J를 사용할 때는 브리징 API와 바인딩을 이해하는 것이 중요합니다. 프로그램이 시작될 때 SLF4J 오류 메시지가 나타나면 Maven의 dependency:tree 명령을 사용하여 종속성을 정렬할 수 있습니다.
- 비동기 로그는 공간을 시간과 교환하여 성능 문제를 해결합니다. 하지만 결국 공간은 제한되어 있습니다. 공간이 가득 차면 차단하고 기다리거나 로그를 삭제하는 것을 고려해야 합니다. 중요한 로그를 삭제하지 않으려면 차단 대기를 선택하고, 로깅으로 인해 프로그램이 차단되지 않도록 하려면 로그를 삭제해야 합니다.
- 로그 프레임워크에서 제공하는 매개변수화된 로깅 방법은 로그 수준 판단을 완전히 대체할 수 없습니다. 로그 볼륨이 크고 로그 매개변수를 얻는 비용도 높은 경우, 로깅 없이 로그 매개변수를 얻는 데 시간이 많이 걸리지 않도록 로그 수준을 결정해야 합니다.
위 내용은 Java 로그 수준, 중복 기록, 로그 손실 문제 이해의 상세 내용입니다. 자세한 내용은 PHP 중국어 웹사이트의 기타 관련 기사를 참조하세요!