From b62af05bcfffa2cafb096b87eddd3ed27a014e49 Mon Sep 17 00:00:00 2001 From: Leo <414563035@qq.com> Date: Mon, 9 Dec 2024 19:42:04 +0800 Subject: [PATCH] =?UTF-8?q?fix:=20=E4=BF=AE=E5=A4=8D=E6=A8=A1=E5=9D=97?= =?UTF-8?q?=E5=90=8D=E7=A7=B0=E9=97=AE=E9=A2=98?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- README.md | 65 ++++-- .../artlibs/autotrace4j/AutoTrace4j.java | 12 +- .../autotrace4j/context/TraceContext.java | 70 +------ .../autotrace4j/context/TraceInjector.java | 185 ++++++++++++++++++ .../autotrace4j/logger/LogConstants.java | 1 + .../autotrace4j/logger/LoggerFactory.java | 62 +++--- .../logger/appender/AsyncAppender.java | 10 +- ...reamAppender.java => ConsoleAppender.java} | 4 +- ...ultFileAppender.java => FileAppender.java} | 40 ++-- .../logger/layout/DefaultLayout.java | 10 +- .../autotrace4j/support/ModuleUtils.java | 2 +- .../autotrace4j/support/ThrowableUtils.java | 8 +- .../transformer/TransformListener.java | 30 +-- .../impl/CommonSimpleLogTransformer.java | 4 +- .../impl/Log4j2StringLayoutTransformer.java | 57 ++++++ .../impl/Log4jQuietWriterTransformer.java | 6 +- .../impl/LogbackLog4jAsyncTransformer.java | 15 +- .../impl/LogbackLog4jEventTransformer.java | 10 +- .../impl/LogbackOutStreamTransformer.java | 5 +- .../impl/jdk/JavaUtilLoggingTransformer.java | 4 +- .../artlibs/autotrace4j/LoggerTest.java | 117 +++++------ 21 files changed, 488 insertions(+), 229 deletions(-) create mode 100644 src/main/java/io/github/artlibs/autotrace4j/context/TraceInjector.java rename src/main/java/io/github/artlibs/autotrace4j/logger/appender/{DefaultPrintStreamAppender.java => ConsoleAppender.java} (93%) rename src/main/java/io/github/artlibs/autotrace4j/logger/appender/{DefaultFileAppender.java => FileAppender.java} (88%) create mode 100644 src/main/java/io/github/artlibs/autotrace4j/transformer/impl/Log4j2StringLayoutTransformer.java diff --git a/README.md b/README.md index fa73948..5662fc0 100644 --- a/README.md +++ b/README.md @@ -1,13 +1,11 @@ ## Auto Trace for Java -[![Run Tests](https://github.com/artlibs/autotrace4j/actions/workflows/testing.yml/badge.svg)](https://github.com/artlibs/autotrace4j/actions/workflows/testing.yml) [![Maven Central](https://maven-badges.herokuapp.com/maven-central/io.github.artlibs/autotrace4j/badge.svg)](https://maven-badges.herokuapp.com/maven-central/io.github.artlibs/autotrace4j/) [![Release](https://img.shields.io/github/release/artlibs/autotrace4j.svg?style=flat-square)](https://github.com/artlibs/autotrace4j/releases) [![License: Apache 2.0](https://img.shields.io/badge/license-Apache%202.0-blue.svg?style=flat)](https://www.apache.org/licenses/LICENSE-2.0) +[![Run Tests](https://github.com/artlibs/autotrace4j/actions/workflows/testing.yml/badge.svg)](https://github.com/artlibs/autotrace4j/actions/workflows/testing.yml) [![Release](https://img.shields.io/github/release/artlibs/autotrace4j.svg?style=flat-square)](https://github.com/artlibs/autotrace4j/releases) [![License: Apache 2.0](https://img.shields.io/badge/license-Apache%202.0-blue.svg?style=flat)](https://www.apache.org/licenses/LICENSE-2.0) ​ `autotrace4j`是一个基于ByteBuddy编写的轻量级日志跟踪工具，其基本逻辑是在各个上下文当中通过代码增强关键节点来传递`trace id`，最后在日志输出时注入到输出结果当中，以实现日志的跟踪串联。 -​ 我们借鉴了SkyWalking的实现原理，使用ByteBuddy在各个上下文环节进行关键点增强来传递Trace ID。 - #### 易使用 -​ 基于Agent的方式来使用该工具，对业务代码无侵入。 +​ 基于Agent的方式来使用该工具，对业务代码无侵入、运维可在基础层面统一配置，业务方可无感知。 #### 轻量级 @@ -18,9 +16,26 @@ ​ `autotrace4j`的使用非常简单，只需从[release](https://github.com/artlibs/autotrace4j/releases)中下载最新的agent jar包，在启动脚本中以agent方式运行： ```shell -$ java -javaagent=/dir/to/autotrace4j.jar=com.your-domain.biz1.pkg1,com.your-domain.biz2.pkg2 -jar YourJar.jar # 省略其他无关参数 +$ java -javaagent=/dir/to/autotrace4j.jar=com.your-domain.biz1.pkg1,com.your-domain.biz2.pkg2 -Dautotrace4j.log.enable=true -jar YourJar.jar # 省略其他无关参数 ``` +- 一般情况下不需要开启autotrace4j内部日志，即***不需要***`-Dautotrace4j.log.enable=true`，如果需要观测到增强过程增强了哪些类，或在调试autotrace4j时有需要，可开启该日志选项，其他选项可使用默认参数： + - `-Dautotrace4j.log.enable=true` 设置开启autotrace4j内部日志 + - `-Dautotrace4j.log.dir=/path/to/your/log/dir` 修改autotrace4j内部日志保存路径 + - `-Dautotrace4j.log.level=TRACE` （可选`TRACE`, `DEBUG`, `INFO`, `WARN`, `ERROR`）修改日志级别 + - `-Dautotrace4j.log.file.retention=5` 设置autotrace4j内部日志保留天数为5天 + - `-Dautotrace4j.log.file.size=10485760`设置单个文件大小为10M(`10*1024*1024=10485760`) + +#### 关于日志 + +可通过如下系统属性开启和设置日志来观察增强过程： + +- `autotrace4j.log.enable`：是否开启autotrace4j日志，默认`false` +- `autotrace4j.log.dir`：autotrace4j日志文件保存路径，默认为临时目录`java.io.tmpdir` +- `autotrace4j.log.level`：autotrace4j日志级别，默认为`DEBUG` +- `autotrace4j.log.file.retention`：autotrace4j日志文件保留时间，单位天，默认为`7`天 +- `autotrace4j.log.file.size`：autotrace4j日志文件大小限制，单位字节(`B`)，默认为`0`表示不限制 + #### 关于`MDC` 可通过`slf4j`或者`log4j`的`MDC`获取当前上下文的Trace ID： @@ -33,7 +48,7 @@ $ java -javaagent=/dir/to/autotrace4j.jar=com.your-domain.biz1.pkg1,com.your-dom ### 1、Thread -​ 针对Thread进行了增强，在创建线程时支持自动Trace跟踪: `java.lang.Thread` +​ 针对Thread进行了增强，在创建线程时支持自动传递当前Trace: `java.lang.Thread` ### 2、Thread Pool @@ -58,17 +73,18 @@ $ java -javaagent=/dir/to/autotrace4j.jar=com.your-domain.biz1.pkg1,com.your-dom - `javax.servlet.Filter` - `javax.servlet.http.HttpServlet` -### 5、MessageQunue +### 5、Middleware -​ 目前支持阿里云ONS和RocketMQ在生产和消费时带上TraceId： +​ 支持阿里云ONS和RocketMQ在生产和消费时传递trace，支持Dubbo： - RocektMQ：`Producer` & `Consumer` - Aliyun ONS：`Producer` & `Consumer` -- Kafka：comming soon.... +- Dubbo：`org.apache.dubbo.rpc.protocol.dubbo.filter.TraceFilter` + `org.apache.dubbo.rpc.protocol.dubbo.filter.FutureFilter` -### 6、Scheduled Task +### 6、Scheduled -​ 支持XXL Job、Spring Scheduled定时任务、PowerJob在产生时生成TraceId： +​ 支持XXL Job、Spring Scheduled定时任务、PowerJob在产生时传递TraceId： - XxlJob Handler：`com.handler.com.xxl.job.core.IJobHandler` - Spring Schedule Task：`org.springframework.scheduling.annotation.Scheduled` @@ -76,19 +92,26 @@ $ java -javaagent=/dir/to/autotrace4j.jar=com.your-domain.biz1.pkg1,com.your-dom ### 7、Logging -​ 支持在logback中输出日志时注入trace id进行输出： +​ 支持几个主流日志框架的最终输出，自动加入trace信息(主要针对Stream和RollingFile的字符串和JSON格式)： -- Log4j：`log4j:log4j` -- logback：`ch.qos.logback:logback-core` -- Java loggin：`java.util.logging` +- `JUL`、`Log4j`、`Logback`、`Log4j2` -### 8、Middleware +## Contribute -​ 支持如下中间件的增强 +欢迎贡献你的代码(`Fork` & `Pull Request`)，一起完善`autotrace4j`库！ -- Dubbo：`org.apache.dubbo.rpc.protocol.dubbo.filter.TraceFilter` - `org.apache.dubbo.rpc.protocol.dubbo.filter.FutureFilter` +- 如何增加支持： -## Contribute + 在`io.github.artlibs.autotrace4j.transformer`下仿照其他转换器新增 + +- 关于单元测试： + + 在`io.github.artlibs.autotrace4j.At4jTest`中参考其他案例增加单元测试 + +本地单测： + +```shell +$ export JAVA_HOME=/path/to/your/jdk21/home +$ make test +``` -欢迎贡献你的代码，一起完善`autotrace4j`库！ diff --git a/src/main/java/io/github/artlibs/autotrace4j/AutoTrace4j.java b/src/main/java/io/github/artlibs/autotrace4j/AutoTrace4j.java index bc9140d..2e58ab3 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/AutoTrace4j.java +++ b/src/main/java/io/github/artlibs/autotrace4j/AutoTrace4j.java @@ -18,6 +18,8 @@ import java.util.List; import java.util.Objects; +import static io.github.artlibs.autotrace4j.logger.LoggerFactory.getLogFileDirectory; +import static io.github.artlibs.autotrace4j.logger.LoggerFactory.loggerEnabled; import static net.bytebuddy.matcher.ElementMatchers.nameStartsWith; /** @@ -87,11 +89,17 @@ public static Transformer withBizScope(String bizPackages) { */ public void on(Instrumentation instrument) throws IOException, URISyntaxException { String contextPackage = AutoTrace4j.class.getPackage().getName() + ".context"; + + // inject context class into bootstrap loader ClassUtils.injectClassToBootStrap(instrument, contextPackage); - // note: this method must be called after injectClassToBootStrap, don't move it forward + // note: this method must be called after injectClassToBootStrap ModuleUtils.compatibleJavaModule(contextPackage); + if (loggerEnabled()) { + System.err.println("已开启[autotrace4j]日志：" + getLogFileDirectory()); + } + AgentBuilder builder = this.newAgentBuilder(); for (At4jTransformer transformer : loadTransformers()) { builder = builder.type(transformer.typeMatcher()).transform(transformer); @@ -99,8 +107,8 @@ public void on(Instrumentation instrument) throws IOException, URISyntaxExceptio builder.installOn(instrument); // init trace for main thread. - TraceContext.setTraceId(TraceContext.generate()); TraceContext.setSpanId(TraceContext.generate()); + TraceContext.setTraceId(TraceContext.generate()); } /** diff --git a/src/main/java/io/github/artlibs/autotrace4j/context/TraceContext.java b/src/main/java/io/github/artlibs/autotrace4j/context/TraceContext.java index a068498..9f9d8cd 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/context/TraceContext.java +++ b/src/main/java/io/github/artlibs/autotrace4j/context/TraceContext.java @@ -1,10 +1,9 @@ package io.github.artlibs.autotrace4j.context; -import java.util.Objects; import java.util.UUID; /** - * Trace context for SpanId, ParentSpanId, TraceId + * Trace context * * @author Fury * @since 2024-03-30 @@ -138,71 +137,4 @@ public static String generate() { .replace("-", ""); } - private static final String SEPARATOR = " - "; - private static final String QUOTE_COLON = "\":\""; - - /** - * Inject trace id into log message - * @param message String - * @return result - */ - public static String injectTraceId(String message) { - if (Objects.isNull(message) || Objects.isNull(TraceContext.getTraceId())) { - return message; - } - - try { - String trimMessage = message.trim(); - - // JSON FORMAT - if (trimMessage.startsWith("{") && trimMessage.endsWith("}")) { - return injectJsonString(message, trimMessage); - } - - // TODO: XML FORMAT - - // TODO: HTML FORMAT - - return injectString(message); - } catch (Exception e) { - e.printStackTrace(); - } - - return message; - } - - private static String injectString(String message) { - if (message.trim().isEmpty() || message.contains("[TraceId]" + TraceContext.getTraceId())) { - return message; - } - - String preTrimMessage = "[TraceId]" + TraceContext.getTraceId() + SEPARATOR; - if (Objects.nonNull(TraceContext.getSpanId())) { - preTrimMessage += "[SpanId]" + TraceContext.getSpanId() + SEPARATOR; - } - if (Objects.nonNull(TraceContext.getParentSpanId())) { - preTrimMessage += "[P-SpanId]" + TraceContext.getParentSpanId() + SEPARATOR; - } - - return preTrimMessage + message; - } - - private static String injectJsonString(String message, String trimMessage) { - if (message.contains(TraceContext.ATO_TRACE_ID) && message.contains(TraceContext.getTraceId())) { - return message; - } - - String injectedTraceFields = "\"" + TraceContext.ATO_TRACE_ID + QUOTE_COLON + TraceContext.getTraceId() + "\","; - if (Objects.nonNull(TraceContext.getSpanId())) { - injectedTraceFields = injectedTraceFields - + "\"" + TraceContext.ATO_SPAN_ID + QUOTE_COLON + TraceContext.getSpanId() + "\","; - } - if (Objects.nonNull(TraceContext.getParentSpanId())) { - injectedTraceFields = injectedTraceFields - + "\"" + TraceContext.ATO_PARENT_SPAN_ID + QUOTE_COLON + TraceContext.getParentSpanId() + "\","; - } - trimMessage = "{" + injectedTraceFields + trimMessage.substring(1); - - return message.endsWith("\n") ? trimMessage + "\n" : trimMessage; - } } diff --git a/src/main/java/io/github/artlibs/autotrace4j/context/TraceInjector.java b/src/main/java/io/github/artlibs/autotrace4j/context/TraceInjector.java new file mode 100644 index 0000000..88de501 --- /dev/null +++ b/src/main/java/io/github/artlibs/autotrace4j/context/TraceInjector.java @@ -0,0 +1,185 @@ +package io.github.artlibs.autotrace4j.context; + +import java.util.Objects; + +import static io.github.artlibs.autotrace4j.context.TraceContext.*; + +/** + * Trace Injector + * + * @author Fury + * @since 2024-12-08 + *

+ * All rights Reserved. + */ +public interface TraceInjector { + TraceInjector DF = new TraceInjector(){/* default trace injector */}; + + /** + * inject trace into log msg + * @param logMsg - + * @return - + */ + default String injectTrace(String logMsg) { + if (Objects.isNull(logMsg) || logMsg.trim().isEmpty()) { + return logMsg; + } + + try { + String trimMsg = logMsg.trim(); + for (Format fmt : Format.values()) { + if (fmt.detect(trimMsg)) { + return fmt.inject(logMsg, trimMsg); + } + } + + return Format.DEFAULT.inject(logMsg, logMsg.trim()); + } catch (Exception e) { + e.printStackTrace(); + } + + return logMsg; + } + + enum Format { + CSV { + /** + * {@inheritDoc} + */ + @Override + public boolean detect(String trimMsg) { + // TODO: not support yet + return false; + } + + /** + * {@inheritDoc} + */ + @Override + public String inject(String logMsg, String trimMsg) { + // TODO: not support yet + return logMsg; + } + }, + JSON { + /** + * {@inheritDoc} + */ + @Override + public boolean detect(String trimMsg) { + return trimMsg.startsWith("{") && trimMsg.endsWith("}"); + } + + /** + * {@inheritDoc} + */ + @Override + public String inject(String logMsg, String trimMsg) { + if (logMsg.contains(ATO_TRACE_ID) && logMsg.contains(getTraceId())) { + return logMsg; + } + + String injectedTraceFields = "\"" + ATO_TRACE_ID + + QUOTE_COLON + getTraceId() + "\","; + if (Objects.nonNull(getSpanId())) { + injectedTraceFields = injectedTraceFields + "\"" + ATO_SPAN_ID + + QUOTE_COLON + getSpanId() + "\","; + } + if (Objects.nonNull(getParentSpanId())) { + injectedTraceFields = injectedTraceFields + "\"" + ATO_PARENT_SPAN_ID + + QUOTE_COLON + getParentSpanId() + "\","; + } + trimMsg = "{" + injectedTraceFields + trimMsg.substring(1); + + return logMsg.endsWith("\n") ? trimMsg + "\n" : trimMsg; + } + }, + XML { + /** + * {@inheritDoc} + */ + @Override + public boolean detect(String trimMsg) { + // TODO: not support yet + return false; + } + + /** + * {@inheritDoc} + */ + @Override + public String inject(String logMsg, String trimMsg) { + // TODO: not support yet + return logMsg; + } + }, + HTML { + /** + * {@inheritDoc} + */ + @Override + public boolean detect(String trimMsg) { + // TODO: not support yet + return false; + } + + /** + * {@inheritDoc} + */ + @Override + public String inject(String logMsg, String trimMsg) { + // TODO: not support yet + return logMsg; + } + }, + DEFAULT { + /** + * {@inheritDoc} + */ + @Override + public boolean detect(String trimMsg) { + // 默认当成纯文本字符串 + return true; + } + + /** + * {@inheritDoc} + */ + @Override + public String inject(String logMsg, String trimMsg) { + if (logMsg.trim().isEmpty() || logMsg.contains("[TraceId]" + getTraceId())) { + return logMsg; + } + + String preTrimMessage = "[TraceId]" + getTraceId() + SEPARATOR; + if (Objects.nonNull(getSpanId())) { + preTrimMessage += "[SpanId]" + getSpanId() + SEPARATOR; + } + if (Objects.nonNull(getParentSpanId())) { + preTrimMessage += "[P-SpanId]" + getParentSpanId() + SEPARATOR; + } + + return preTrimMessage + logMsg; + } + }, + ; + + /** + * 检测文本是否是指定格式 + * @param trimMsg - + * @return - + */ + abstract boolean detect(String trimMsg); + + /** + * 注入trace到log消息中 + * @param logMsg - + * @param trimMsg - + * @return - + */ + abstract String inject(String logMsg, String trimMsg); + + private static final String SEPARATOR = " - "; + private static final String QUOTE_COLON = "\":\""; + } +} diff --git a/src/main/java/io/github/artlibs/autotrace4j/logger/LogConstants.java b/src/main/java/io/github/artlibs/autotrace4j/logger/LogConstants.java index 06d85a6..076e3a1 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/logger/LogConstants.java +++ b/src/main/java/io/github/artlibs/autotrace4j/logger/LogConstants.java @@ -16,6 +16,7 @@ private LogConstants(){} public static final String RIGHT_MIDDLE_BRACKET = "]"; public static final String CAUSED_BY = "Caused by: "; + public static final String SYSTEM_PROPERTY_LOG_ENABLE = "autotrace4j.log.enable"; public static final String SYSTEM_PROPERTY_LOG_DIR = "autotrace4j.log.dir"; public static final String SYSTEM_PROPERTY_LOG_LEVEL = "autotrace4j.log.level"; public static final String SYSTEM_PROPERTY_LOG_FILE_RETENTION = "autotrace4j.log.file.retention"; diff --git a/src/main/java/io/github/artlibs/autotrace4j/logger/LoggerFactory.java b/src/main/java/io/github/artlibs/autotrace4j/logger/LoggerFactory.java index 2472e74..eb1f727 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/logger/LoggerFactory.java +++ b/src/main/java/io/github/artlibs/autotrace4j/logger/LoggerFactory.java @@ -1,16 +1,19 @@ package io.github.artlibs.autotrace4j.logger; import io.github.artlibs.autotrace4j.logger.appender.AppenderCombiner; -import io.github.artlibs.autotrace4j.logger.appender.DefaultFileAppender; -import io.github.artlibs.autotrace4j.logger.appender.DefaultPrintStreamAppender; +import io.github.artlibs.autotrace4j.logger.appender.FileAppender; +import io.github.artlibs.autotrace4j.logger.appender.ConsoleAppender; import io.github.artlibs.autotrace4j.logger.event.Level; import io.github.artlibs.autotrace4j.logger.event.LogEvent; import io.github.artlibs.autotrace4j.logger.layout.DefaultLayout; import io.github.artlibs.autotrace4j.support.SystemUtils; +import java.nio.file.Path; import java.util.Optional; import java.util.concurrent.ConcurrentHashMap; +import static io.github.artlibs.autotrace4j.logger.LogConstants.*; + /** * 功能：日志工厂 *

@@ -35,35 +38,50 @@ private LoggerFactory(){} static { // appender set APPENDER_COMBINER = new AppenderCombiner<>(); - DefaultPrintStreamAppender defaultPrintStreamAppender = new DefaultPrintStreamAppender(new DefaultLayout(), System.out, System.err); - defaultPrintStreamAppender.start(); - APPENDER_COMBINER.addAppender(defaultPrintStreamAppender); - SystemUtils.getSysPropertyPath(LogConstants.SYSTEM_PROPERTY_LOG_DIR) - .ifPresent(path -> { - DefaultFileAppender defaultFileAppender = new DefaultFileAppender( - new DefaultLayout(), - path, - SystemUtils - .getSysPropertyInteger(LogConstants.SYSTEM_PROPERTY_LOG_FILE_RETENTION) - .orElse(LogConstants.DEFAULT_LOG_FILE_RETENTION), - SystemUtils - .getSysPropertyInteger(LogConstants.SYSTEM_PROPERTY_LOG_FILE_SIZE) - .orElse(LogConstants.DEFAULT_LOG_FILE_SIZE) - ); - defaultFileAppender.start(); - APPENDER_COMBINER.addAppender(defaultFileAppender); - }); + + if (loggerEnabled()) { + ConsoleAppender consoleAppender = new ConsoleAppender(new DefaultLayout(), System.out, System.err); + consoleAppender.start(); + APPENDER_COMBINER.addAppender(consoleAppender); + + FileAppender fileAppender = new FileAppender( + new DefaultLayout(), getLogFileDirectory(), + SystemUtils.getSysPropertyInteger(SYSTEM_PROPERTY_LOG_FILE_RETENTION) + .orElse(DEFAULT_LOG_FILE_RETENTION), + SystemUtils.getSysPropertyInteger(SYSTEM_PROPERTY_LOG_FILE_SIZE) + .orElse(DEFAULT_LOG_FILE_SIZE) + ); + fileAppender.start(); + APPENDER_COMBINER.addAppender(fileAppender); + } + APPENDER_COMBINER.start(); + // level set LEVEL = getLevelConfig(); } + public static boolean loggerEnabled() { + return Boolean.TRUE.equals(SystemUtils.getSysPropertyBool(SYSTEM_PROPERTY_LOG_ENABLE) + .orElse(Boolean.FALSE)); + } + + public static Path getLogFileDirectory() { + Path directory = SystemUtils.getSysPropertyPath(SYSTEM_PROPERTY_LOG_DIR) + .orElse(SystemUtils.getSysTempDir()); + if (!directory.endsWith("autotrace4j")) { + directory = directory.resolve("autotrace4j"); + } + + return directory; + } + private static Level getLevelConfig() { return Optional - .ofNullable(System.getProperty(LogConstants.SYSTEM_PROPERTY_LOG_LEVEL)) + .ofNullable(System.getProperty(SYSTEM_PROPERTY_LOG_LEVEL)) .map(String::toUpperCase) .map(Level::valueOf) - .orElse(Level.INFO); + .orElse(Level.DEBUG); } public static Logger getLogger(Class clazz) { diff --git a/src/main/java/io/github/artlibs/autotrace4j/logger/appender/AsyncAppender.java b/src/main/java/io/github/artlibs/autotrace4j/logger/appender/AsyncAppender.java index 0aefad8..507e8d5 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/logger/appender/AsyncAppender.java +++ b/src/main/java/io/github/artlibs/autotrace4j/logger/appender/AsyncAppender.java @@ -29,7 +29,7 @@ protected AsyncAppender() { @Override public boolean start() { - new Thread(() -> { + Thread async = new Thread(() -> { while (true) { try { if (started()) { @@ -40,7 +40,13 @@ public boolean start() { System.err.println(ThrowableUtils.throwableToStr(e)); } } - }).start(); + }); + + // Fix: 设置成守护线程以防止主线程退出时阻止JVM的停止 + async.setDaemon(true); + + async.start(); + return super.start(); } diff --git a/src/main/java/io/github/artlibs/autotrace4j/logger/appender/DefaultPrintStreamAppender.java b/src/main/java/io/github/artlibs/autotrace4j/logger/appender/ConsoleAppender.java similarity index 93% rename from src/main/java/io/github/artlibs/autotrace4j/logger/appender/DefaultPrintStreamAppender.java rename to src/main/java/io/github/artlibs/autotrace4j/logger/appender/ConsoleAppender.java index 9e59864..89870b8 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/logger/appender/DefaultPrintStreamAppender.java +++ b/src/main/java/io/github/artlibs/autotrace4j/logger/appender/ConsoleAppender.java @@ -16,12 +16,12 @@ *

* All rights Reserved. */ -public class DefaultPrintStreamAppender extends AsyncAppender { +public class ConsoleAppender extends AsyncAppender { Layout layout; private final PrintStream outPrintStream; private final PrintStream errPrintStream; - public DefaultPrintStreamAppender( + public ConsoleAppender( Layout layout, PrintStream outPrintStream, PrintStream errPrintStream diff --git a/src/main/java/io/github/artlibs/autotrace4j/logger/appender/DefaultFileAppender.java b/src/main/java/io/github/artlibs/autotrace4j/logger/appender/FileAppender.java similarity index 88% rename from src/main/java/io/github/artlibs/autotrace4j/logger/appender/DefaultFileAppender.java rename to src/main/java/io/github/artlibs/autotrace4j/logger/appender/FileAppender.java index c6068d6..e436d49 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/logger/appender/DefaultFileAppender.java +++ b/src/main/java/io/github/artlibs/autotrace4j/logger/appender/FileAppender.java @@ -44,10 +44,11 @@ * All rights Reserved. */ @SuppressWarnings({"resource", "UnusedReturnValue" }) -public class DefaultFileAppender extends AsyncAppender { +public class FileAppender extends AsyncAppender { public static final int MIN_FILE_SIZE = 10 * 1024 * 1024; private static final int WRITE_BUFFER_SIZE = 1024; + private static final String FILE_SUFFIX = ".log"; private final Layout layout; private final Path directory; @@ -65,17 +66,18 @@ public class DefaultFileAppender extends AsyncAppender { @SuppressWarnings("FieldMayBeFinal") private int logFileSizeBytes; - private final ThreadLocal logWriteBuffer = ThreadLocal.withInitial(() -> ByteBuffer.allocateDirect(WRITE_BUFFER_SIZE)); + private final ThreadLocal logWriteBuffer = ThreadLocal.withInitial( + () -> ByteBuffer.allocateDirect(WRITE_BUFFER_SIZE)); - public DefaultFileAppender(Layout layout, Path directory) { + public FileAppender(Layout layout, Path directory) { this(layout, directory, DEFAULT_LOG_FILE_RETENTION, DEFAULT_LOG_FILE_SIZE); } - public DefaultFileAppender(Layout layout, Path directory, int logFileRetentionDays) { + public FileAppender(Layout layout, Path directory, int logFileRetentionDays) { this(layout, directory, logFileRetentionDays, DEFAULT_LOG_FILE_SIZE); } - public DefaultFileAppender(Layout layout, Path directory, int logFileRetentionDays, int logFileSizeBytes) { + public FileAppender(Layout layout, Path directory, int logFileRetentionDays, int logFileSizeBytes) { if (Objects.isNull(directory) || (Files.exists(directory) && !Files.isDirectory(directory))) { throw new CreateAppenderException("log directory missing, it will not record any log event"); } @@ -110,10 +112,9 @@ private void init() { private int computeFileIndex(LocalDateTime date, boolean increment) throws IOException { String todayFileNamePrefix = dateToLogFileName(date); - return Files - .list(directory) + return Files.list(directory).filter(p -> p.toString().endsWith(FILE_SUFFIX)) .map(path -> { - String fileName = path.getFileName().toString(); + String fileName = path.getFileName().toString().replace(FILE_SUFFIX, ""); int prefixIndex = fileName.lastIndexOf(todayFileNamePrefix); if (prefixIndex != -1) { if (fileName.length() == todayFileNamePrefix.length()) { @@ -168,7 +169,6 @@ void doAppend(LogEvent event) { } catch (Exception e) { System.err.println(ThrowableUtils.throwableToStr(e)); } - } private Tuple2 getLogFile(int messageLength) throws IOException { @@ -203,12 +203,20 @@ private Tuple2 getLogFile(int messageLength) throws IOExcepti return fileAndChannel; } + /** + * 清理工作只在记录日志时'顺带'触发，而转换只在加载时触发，因此在系统启动一段时间之后便大概率不会 + * 再有日志，因此如果系统长期不重启，那么日志清理将不会被触发，真正的清理工作将在下一次系统重启时 + * 进行（这个效果也是挺好，即启动时的增强日志被'长期保留' —— 除非在临时目录被系统清理）；另一种做 + * 法是使用scheduleAtFixedRate方法定时清理，但鉴于上诉的'良好效果'，不做此修改。 + * @param date - + * @return - + */ private ScheduledFuture triggerCleanTask(LocalDateTime date) { return scheduledExecutorService.schedule(new CleanerTask(date, this), 0, TimeUnit.MILLISECONDS); } private Tuple2 openLogFile(String logFileNamePrefix, int fileIndex) throws IOException { - Path path = directory.resolve(logFileNamePrefix + (fileIndex == 0 ? "" : "-" + fileIndex)); + Path path = directory.resolve(logFileNamePrefix + (fileIndex == 0 ? "" : "_" + fileIndex) + FILE_SUFFIX); FileChannel fileChannel = FileChannel.open(path, StandardOpenOption.APPEND, StandardOpenOption.CREATE); return new Tuple2<>(path, fileChannel); } @@ -245,8 +253,8 @@ private void cleanExpiredFiles(LocalDateTime triggerDate) throws IOException { LocalDateTime expiredTime = triggerDate .with(LocalTime.MIN) .minusDays(logFileRetentionDays); - Files.list(directory) - .map(DefaultFileAppender::mapPathToLogFile) + Files.list(directory).filter(p -> p.toString().endsWith(FILE_SUFFIX)) + .map(FileAppender::mapPathToLogFile) .filter(Optional::isPresent) .map(Optional::get) .sorted(Comparator.comparing(Tuple2::getFirst)) @@ -310,17 +318,17 @@ private static class CleanerTask implements Runnable { * expiredDate's date and before will be deleted. */ private final LocalDateTime triggerDate; - private final DefaultFileAppender defaultFileAppender; + private final FileAppender fileAppender; - public CleanerTask(LocalDateTime triggerDate, DefaultFileAppender defaultFileAppender) { + public CleanerTask(LocalDateTime triggerDate, FileAppender fileAppender) { this.triggerDate = triggerDate; - this.defaultFileAppender = defaultFileAppender; + this.fileAppender = fileAppender; } @Override public void run() { try { - defaultFileAppender.cleanExpiredFiles(triggerDate); + fileAppender.cleanExpiredFiles(triggerDate); } catch (Exception e) { System.err.println("[DefaultFileAppender] clean expired log files failed."); System.err.println(ThrowableUtils.throwableToStr(e)); diff --git a/src/main/java/io/github/artlibs/autotrace4j/logger/layout/DefaultLayout.java b/src/main/java/io/github/artlibs/autotrace4j/logger/layout/DefaultLayout.java index 92142e5..119f2e8 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/logger/layout/DefaultLayout.java +++ b/src/main/java/io/github/artlibs/autotrace4j/logger/layout/DefaultLayout.java @@ -21,7 +21,7 @@ */ public class DefaultLayout implements Layout { - public static final String UN_DEFINE = "unDefine"; + public static final String UNDEFINE = "undefine"; @Override public String format(LogEvent event) { @@ -33,12 +33,12 @@ public String format(LogEvent event) { .ofNullable(event.getEventTime()) .map(eventTime -> LocalDateTime.ofInstant(Instant.ofEpochMilli(event.getEventTime()), ZoneId.systemDefault())) .map(LocalDateTime::toString) - .orElse(UN_DEFINE), + .orElse(UNDEFINE), sb ); - appendItem(Optional.ofNullable(event.getThreadName()).orElse(UN_DEFINE), sb); - appendItem(Optional.ofNullable(event.getLevel()).map(Enum::name).orElse(UN_DEFINE), sb); - appendItem(Optional.ofNullable(logger).map(Logger::getName).orElse(UN_DEFINE), sb); + appendItem(Optional.ofNullable(event.getThreadName()).orElse(UNDEFINE), sb); + appendItem(Optional.ofNullable(event.getLevel()).map(Enum::name).orElse(UNDEFINE), sb); + appendItem(Optional.ofNullable(logger).map(Logger::getName).orElse(UNDEFINE), sb); sb.append("-"); sb.append(SPACE); sb.append(String.format(event.getMessage(), event.getArguments())); diff --git a/src/main/java/io/github/artlibs/autotrace4j/support/ModuleUtils.java b/src/main/java/io/github/artlibs/autotrace4j/support/ModuleUtils.java index 2ff40e4..b2ee59e 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/support/ModuleUtils.java +++ b/src/main/java/io/github/artlibs/autotrace4j/support/ModuleUtils.java @@ -162,7 +162,7 @@ private static Object getJdkBaseModule() { Object bootLayer = mBoot.invoke(null); Class cOptional = Class.forName("java.util.Optional"); Method mFindModule = cModuleLayer.getDeclaredMethod("findModule", String.class); - Object oCompilerO = mFindModule.invoke(bootLayer, "java.abs"); + Object oCompilerO = mFindModule.invoke(bootLayer, "java.base"); return cOptional.getDeclaredMethod("get").invoke(oCompilerO); } catch (Exception e) { return null; diff --git a/src/main/java/io/github/artlibs/autotrace4j/support/ThrowableUtils.java b/src/main/java/io/github/artlibs/autotrace4j/support/ThrowableUtils.java index 785f2e6..98afaa2 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/support/ThrowableUtils.java +++ b/src/main/java/io/github/artlibs/autotrace4j/support/ThrowableUtils.java @@ -26,15 +26,15 @@ public static String throwableToStr(Throwable t) { private static void extract(List strList, Throwable t, StackTraceElement[] parentSTE) { StackTraceElement[] ste = t.getStackTrace(); - final int numberOfcommonFrames = findNumberOfCommonFrames(ste, parentSTE); + final int numberOfCommonFrames = findNumberOfCommonFrames(ste, parentSTE); strList.add(formatFirstLine(t, parentSTE)); - for (int i = 0; i < (ste.length - numberOfcommonFrames); i++) { + for (int i = 0; i < (ste.length - numberOfCommonFrames); i++) { strList.add("\tat " + ste[i].toString()); } - if (numberOfcommonFrames != 0) { - strList.add("\t... " + numberOfcommonFrames + " common frames omitted"); + if (numberOfCommonFrames != 0) { + strList.add("\t... " + numberOfCommonFrames + " common frames omitted"); } Throwable cause = t.getCause(); diff --git a/src/main/java/io/github/artlibs/autotrace4j/transformer/TransformListener.java b/src/main/java/io/github/artlibs/autotrace4j/transformer/TransformListener.java index 9f15aad..c9aaabe 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/transformer/TransformListener.java +++ b/src/main/java/io/github/artlibs/autotrace4j/transformer/TransformListener.java @@ -6,6 +6,8 @@ import net.bytebuddy.description.type.TypeDescription; import net.bytebuddy.dynamic.DynamicType; import net.bytebuddy.utility.JavaModule; +import net.bytebuddy.utility.nullability.MaybeNull; +import net.bytebuddy.utility.nullability.NeverNull; /** @@ -18,46 +20,50 @@ */ public final class TransformListener implements AgentBuilder.Listener { private static final Logger logger = LoggerFactory.getLogger(TransformListener.class); + private static final String FORMAT = "\n>>> Type: %s\n>>> ClassLoader: %s\n>>> Module: %s, Loaded: %s"; /** * {@inheritDoc} */ @Override - public void onDiscovery(String typeName, ClassLoader classLoader, JavaModule module, boolean loaded) { - logger.trace("typeName: %s\n classLoader: %s\n module: %s\nloaded: %s", typeName, classLoader, module, loaded); + public void onDiscovery(@NeverNull String type, @MaybeNull ClassLoader classLoader + , @MaybeNull JavaModule module, boolean loaded) { + logger.trace(FORMAT, type, classLoader, module, loaded); } /** * {@inheritDoc} */ @Override - public void onTransformation( - TypeDescription typeDescription, ClassLoader classLoader, JavaModule module, boolean loaded, DynamicType dynamicType - ) { - logger.trace("typeDescription: %s\n classLoader: %s\n module: %s\nloaded: %s\ndynamicType: %s", typeDescription, classLoader, module, loaded, dynamicType); + public void onTransformation(@NeverNull TypeDescription type, @MaybeNull ClassLoader classLoader + , @MaybeNull JavaModule module, boolean loaded, @NeverNull DynamicType dynamicType) { + logger.debug(FORMAT + "\n>>> DynamicType: %s", type, classLoader, module, loaded, dynamicType); } /** * {@inheritDoc} */ @Override - public void onIgnored(TypeDescription typeDescription, ClassLoader classLoader, JavaModule module, boolean loaded) { - logger.trace("typeDescription: %s\n classLoader: %s\n module: %s\nloaded: %s", typeDescription, classLoader, module, loaded); + public void onIgnored(@NeverNull TypeDescription type, @MaybeNull ClassLoader classLoader + , @MaybeNull JavaModule module, boolean loaded) { + logger.trace(FORMAT, type, classLoader, module, loaded); } /** * {@inheritDoc} */ @Override - public void onError(String typeName, ClassLoader classLoader, JavaModule module, boolean loaded, Throwable throwable) { - logger.error("TypeName: %s\n classLoader: %s\n module: %s\n", typeName, classLoader, module, throwable); + public void onError(@NeverNull String type, @MaybeNull ClassLoader classLoader + , @MaybeNull JavaModule module, boolean loaded, @NeverNull Throwable throwable) { + logger.error(FORMAT, type, classLoader, module, loaded, throwable); } /** * {@inheritDoc} */ @Override - public void onComplete(String typeName, ClassLoader classLoader, JavaModule module, boolean loaded) { - logger.trace("TypeName: %s\n classLoader: %s\n module: %s\nloaded: %s", typeName, classLoader, module, loaded); + public void onComplete(@NeverNull String type, @MaybeNull ClassLoader classLoader + , @MaybeNull JavaModule module, boolean loaded) { + logger.trace(FORMAT, type, classLoader, module, loaded); } } diff --git a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/CommonSimpleLogTransformer.java b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/CommonSimpleLogTransformer.java index 586d9ae..c16e1c2 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/CommonSimpleLogTransformer.java +++ b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/CommonSimpleLogTransformer.java @@ -1,12 +1,12 @@ package io.github.artlibs.autotrace4j.transformer.impl; +import io.github.artlibs.autotrace4j.context.TraceInjector; import io.github.artlibs.autotrace4j.transformer.abs.AbsVisitorTransformer; import net.bytebuddy.asm.Advice; import net.bytebuddy.description.type.TypeDescription; import net.bytebuddy.implementation.bytecode.assign.Assigner; import net.bytebuddy.matcher.ElementMatcher; -import static io.github.artlibs.autotrace4j.context.TraceContext.injectTraceId; import static net.bytebuddy.matcher.ElementMatchers.*; /** @@ -46,7 +46,7 @@ protected MethodMatcherHolder methodMatchers() { public static void adviceOnMethodEnter( @Advice.Argument(value = 0, typing = Assigner.Typing.DYNAMIC , readOnly = false) StringBuffer buffer) { - buffer = new StringBuffer(injectTraceId(buffer.toString())); + buffer = new StringBuffer(TraceInjector.DF.injectTrace(buffer.toString())); } } diff --git a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/Log4j2StringLayoutTransformer.java b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/Log4j2StringLayoutTransformer.java new file mode 100644 index 0000000..74779cc --- /dev/null +++ b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/Log4j2StringLayoutTransformer.java @@ -0,0 +1,57 @@ +package io.github.artlibs.autotrace4j.transformer.impl; + +import io.github.artlibs.autotrace4j.context.TraceInjector; +import io.github.artlibs.autotrace4j.transformer.abs.AbsVisitorTransformer; +import net.bytebuddy.asm.Advice; +import net.bytebuddy.description.type.TypeDescription; +import net.bytebuddy.implementation.bytecode.assign.Assigner; +import net.bytebuddy.matcher.ElementMatcher; + +import static net.bytebuddy.matcher.ElementMatchers.*; + +/** + * Logback 增强转换器 + *

+ * @author Fury + * @since 2024-03-30 + * + * All rights Reserved. + */ +public class Log4j2StringLayoutTransformer extends AbsVisitorTransformer { + + /** + * {@inheritDoc} + */ + @Override + public ElementMatcher typeMatcher() { + // log4j2: org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender + // method: directEncodeEvent & writeByteArrayToManager -> layout:encode & layout:toByteArray + // StringLayout有诸多实现：pattern, json, xml, yaml, csv等等，需要注意可能的破坏格式 + return hasSuperType(named("org.apache.logging.log4j.core.layout.Encoder")); + } + + /** + * {@inheritDoc} + */ + @Override + protected MethodMatcherHolder methodMatchers() { + return ofMatcher(isPublic() + .and(named("encode")) + .and(takesArgument(0, StringBuilder.class)) + .and(takesArgument(1, hasSuperType(named("org.apache.logging.log4j.core.layout.ByteBufferDestination")))) + .and(returns(void.class)) + ); + } + + /** + * OnMethodExit + * @param builder - + */ + @Advice.OnMethodEnter + public static void adviceOnMethodEnter( + @Advice.Argument(value = 0, typing = Assigner.Typing.DYNAMIC + , readOnly = false) StringBuilder builder) { + builder = new StringBuilder(TraceInjector.DF.injectTrace(builder.toString())); + } + +} diff --git a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/Log4jQuietWriterTransformer.java b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/Log4jQuietWriterTransformer.java index fa09f6d..1479d5c 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/Log4jQuietWriterTransformer.java +++ b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/Log4jQuietWriterTransformer.java @@ -1,16 +1,16 @@ package io.github.artlibs.autotrace4j.transformer.impl; +import io.github.artlibs.autotrace4j.context.TraceInjector; import io.github.artlibs.autotrace4j.transformer.abs.AbsVisitorTransformer; import net.bytebuddy.asm.Advice; import net.bytebuddy.description.type.TypeDescription; import net.bytebuddy.implementation.bytecode.assign.Assigner; import net.bytebuddy.matcher.ElementMatcher; -import static io.github.artlibs.autotrace4j.context.TraceContext.injectTraceId; import static net.bytebuddy.matcher.ElementMatchers.*; /** - * Log4j 增强转换器 + * Log4j的输出注入 *

* @author Fury * @since 2024-03-30 @@ -46,7 +46,7 @@ protected MethodMatcherHolder methodMatchers() { public static void adviceOnMethodEnter( @Advice.Argument(value = 0, typing = Assigner.Typing.DYNAMIC , readOnly = false) String message) { - message = injectTraceId(message); + message = TraceInjector.DF.injectTrace(message); } } diff --git a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/LogbackLog4jAsyncTransformer.java b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/LogbackLog4jAsyncTransformer.java index 7d47165..c8cf8dc 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/LogbackLog4jAsyncTransformer.java +++ b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/LogbackLog4jAsyncTransformer.java @@ -27,8 +27,12 @@ public class LogbackLog4jAsyncTransformer extends AbsVisitorTransformer { */ @Override public ElementMatcher typeMatcher() { - return named("ch.qos.logback.core.spi.AppenderAttachableImpl") - .or(named("org.apache.log4j.helpers.AppenderAttachableImpl")); + return // logback - appendLoopOnAppenders + named("ch.qos.logback.core.spi.AppenderAttachableImpl") + // log4j - appendLoopOnAppenders + .or(named("org.apache.log4j.helpers.AppenderAttachableImpl")) + // log4j2 - + .or(hasSuperType(named("org.apache.logging.log4j.core.config.AppenderControl"))); } /** @@ -36,8 +40,11 @@ public ElementMatcher typeMatcher() { */ @Override protected MethodMatcherHolder methodMatchers() { - return ofMatcher(isPublic().and(named("appendLoopOnAppenders")) - .and(returns(int.class))); + return ofMatcher(isPublic() + // logback & log4j + .and(named("appendLoopOnAppenders").and(returns(int.class))) + // log4j2 + .or(named("callAppender").and(returns(void.class)))); } @Advice.OnMethodEnter diff --git a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/LogbackLog4jEventTransformer.java b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/LogbackLog4jEventTransformer.java index ae98126..3c10aa1 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/LogbackLog4jEventTransformer.java +++ b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/LogbackLog4jEventTransformer.java @@ -7,7 +7,7 @@ import static net.bytebuddy.matcher.ElementMatchers.*; /** - * Logback/Log4j - LoggingEvent 增强转换器 + * Logback/Log4j/Log4j2 - LoggingEvent 增强转换器 *

* @author Fury * @since 2024-03-30 @@ -23,8 +23,12 @@ public class LogbackLog4jEventTransformer extends AbsVisitorTransformer.AbsConst @Override public ElementMatcher typeMatcher() { return not(isInterface()).and(not(isAbstract())).and( - hasSuperType(named("ch.qos.logback.classic.spi.ILoggingEvent")) - .or(hasSuperType(named("org.apache.log4j.spi.LoggingEvent"))) + // logback + hasSuperType(named("ch.qos.logback.classic.spi.ILoggingEvent")).or( + // log4j + hasSuperType(named("org.apache.log4j.spi.LoggingEvent")) + // log4j2 + ).or( hasSuperType(named("org.apache.logging.log4j.core.LogEvent")) ) ); } diff --git a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/LogbackOutStreamTransformer.java b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/LogbackOutStreamTransformer.java index b10e7db..8406822 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/LogbackOutStreamTransformer.java +++ b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/LogbackOutStreamTransformer.java @@ -1,12 +1,12 @@ package io.github.artlibs.autotrace4j.transformer.impl; +import io.github.artlibs.autotrace4j.context.TraceInjector; import io.github.artlibs.autotrace4j.transformer.abs.AbsVisitorTransformer; import net.bytebuddy.asm.Advice; import net.bytebuddy.description.type.TypeDescription; import net.bytebuddy.implementation.bytecode.assign.Assigner; import net.bytebuddy.matcher.ElementMatcher; -import static io.github.artlibs.autotrace4j.context.TraceContext.injectTraceId; import static net.bytebuddy.matcher.ElementMatchers.*; /** @@ -24,6 +24,7 @@ public class LogbackOutStreamTransformer extends AbsVisitorTransformer { */ @Override public ElementMatcher typeMatcher() { + // Supports FileAppender, RollingFileAppender, ConsoleAppender e.g. return hasSuperType(named("ch.qos.logback.core.OutputStreamAppender")); } @@ -46,7 +47,7 @@ protected MethodMatcherHolder methodMatchers() { public static void adviceOnMethodEnter( @Advice.Argument(value = 0, typing = Assigner.Typing.DYNAMIC , readOnly = false) byte[] byteArray) { - byteArray = injectTraceId(new String(byteArray)).getBytes(); + byteArray = TraceInjector.DF.injectTrace(new String(byteArray)).getBytes(); } } diff --git a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/jdk/JavaUtilLoggingTransformer.java b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/jdk/JavaUtilLoggingTransformer.java index 5322448..b5c78de 100644 --- a/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/jdk/JavaUtilLoggingTransformer.java +++ b/src/main/java/io/github/artlibs/autotrace4j/transformer/impl/jdk/JavaUtilLoggingTransformer.java @@ -1,12 +1,12 @@ package io.github.artlibs.autotrace4j.transformer.impl.jdk; +import io.github.artlibs.autotrace4j.context.TraceInjector; import io.github.artlibs.autotrace4j.transformer.abs.AbsVisitorTransformer; import net.bytebuddy.asm.Advice; import net.bytebuddy.description.type.TypeDescription; import net.bytebuddy.implementation.bytecode.assign.Assigner; import net.bytebuddy.matcher.ElementMatcher; -import static io.github.artlibs.autotrace4j.context.TraceContext.injectTraceId; import static net.bytebuddy.matcher.ElementMatchers.*; import static net.bytebuddy.matcher.ElementMatchers.takesArgument; @@ -40,6 +40,6 @@ protected MethodMatcherHolder methodMatchers() { @Advice.OnMethodExit public static void adviceOnMethodExit(@Advice.Return(readOnly = false , typing = Assigner.Typing.DYNAMIC) String result) { - result = injectTraceId(result); + result = TraceInjector.DF.injectTrace(result); } } diff --git a/src/test/java/io/github/artlibs/autotrace4j/LoggerTest.java b/src/test/java/io/github/artlibs/autotrace4j/LoggerTest.java index c27261e..5451ee3 100644 --- a/src/test/java/io/github/artlibs/autotrace4j/LoggerTest.java +++ b/src/test/java/io/github/artlibs/autotrace4j/LoggerTest.java @@ -1,7 +1,6 @@ package io.github.artlibs.autotrace4j; import io.github.artlibs.autotrace4j.context.ReflectUtils; -import io.github.artlibs.autotrace4j.logger.LogConstants; import io.github.artlibs.autotrace4j.logger.Logger; import io.github.artlibs.autotrace4j.logger.LoggerFactory; import io.github.artlibs.autotrace4j.logger.appender.*; @@ -34,6 +33,8 @@ import static io.github.artlibs.autotrace4j.context.ReflectUtils.getField; import static io.github.artlibs.autotrace4j.context.ReflectUtils.getFieldValue; +import static io.github.artlibs.autotrace4j.logger.LogConstants.*; +import static io.github.artlibs.autotrace4j.logger.event.Level.DEBUG; import static io.github.artlibs.autotrace4j.logger.event.Level.INFO; import static io.github.artlibs.autotrace4j.support.FileUtils.deleteDirectoryRecursively; @@ -47,13 +48,15 @@ */ @TestMethodOrder(MethodOrderer.OrderAnnotation.class) public class LoggerTest { - - protected static final Level TEST_DEFAULT_LEVEL = INFO; - protected static final Path LOG_DIR = SystemUtils.getSysTempDir().resolve("test").resolve(LoggerTest.class.getSimpleName()); + protected static final Level TEST_DEFAULT_LEVEL = DEBUG; + protected static final Path LOG_DIR = SystemUtils.getSysTempDir() + .resolve("autotrace4j-test") + .resolve(LoggerTest.class.getSimpleName()); @BeforeAll public static void beforeAll() throws IOException { deleteDirectoryRecursively(LOG_DIR); + System.setProperty(SYSTEM_PROPERTY_LOG_ENABLE, "true"); } @BeforeEach @@ -77,7 +80,6 @@ public void benchMark() throws InterruptedException, IllegalAccessException { System.out.println("toast: " + (endTime - startTime)); } - @Test @Order(1) void defaultLayout() { @@ -107,30 +109,19 @@ void defaultLayout() { ); } - private static Logger newLogger(String name, Appender appender, Level level) { - try { - Constructor declaredConstructor = Logger.class.getDeclaredConstructor(String.class, Appender.class, Level.class); - declaredConstructor.setAccessible(true); - return declaredConstructor - .newInstance(name, appender, level); - } catch (Exception e) { - throw new RuntimeException(e); - } - } - @Test @Order(2) void logConsole() throws IOException, InterruptedException, IllegalAccessException { for (Level limitLevel : Level.values()) { ByteArrayOutputStream logCollectStream = new ByteArrayOutputStream(); PrintStream printStream = new PrintStream(logCollectStream); - DefaultPrintStreamAppender defaultPrintStreamAppender = new DefaultPrintStreamAppender( + ConsoleAppender consoleAppender = new ConsoleAppender( new DefaultLayout(), printStream, printStream ); - defaultPrintStreamAppender.start(); - Logger logger = newLogger(LoggerTest.class.getCanonicalName(), defaultPrintStreamAppender, limitLevel); + consoleAppender.start(); + Logger logger = newLogger(LoggerTest.class.getCanonicalName(), consoleAppender, limitLevel); // test every limit level log print Assertions.assertNotNull(logger); @@ -141,14 +132,14 @@ void logConsole() throws IOException, InterruptedException, IllegalAccessExcepti .invoke(level.name(), new Object[0]); } // waiting for log collect,its async write. - waitingForAsyncAppend(defaultPrintStreamAppender); + waitingForAsyncAppend(consoleAppender); // check console log checkLogContents( logCollectStream.toString(StandardCharsets.UTF_8.name()).split(System.lineSeparator()), logger.getLevel() ); - defaultPrintStreamAppender.stop(); + consoleAppender.stop(); } } @@ -159,9 +150,9 @@ void logFile() throws IOException, InterruptedException, IllegalAccessException Files.createDirectories(logPath); for (Level limitLevel : Level.values()) { // don't clean file - DefaultFileAppender defaultFileAppender = new DefaultFileAppender(new DefaultLayout(), logPath, 0); - defaultFileAppender.start(); - Logger logger = newLogger(LoggerTest.class.getCanonicalName(), defaultFileAppender, limitLevel); + FileAppender fileAppender = new FileAppender(new DefaultLayout(), logPath, 0); + fileAppender.start(); + Logger logger = newLogger(LoggerTest.class.getCanonicalName(), fileAppender, limitLevel); // test every limit level log print // make all level's log for (Level level : Level.values()) { @@ -170,9 +161,9 @@ void logFile() throws IOException, InterruptedException, IllegalAccessException .invoke(level.name(), new Object[0]); } // waiting for log collect,its async write. - waitingForAsyncAppend(defaultFileAppender); + waitingForAsyncAppend(fileAppender); // check file log - Path logFile = logPath.resolve(DefaultFileAppender.dateToLogFileName(LocalDateTime.now())); + Path logFile = logPath.resolve(FileAppender.dateToLogFileName(LocalDateTime.now()) + ".log"); checkLogContents( new String(Files.readAllBytes(logFile), StandardCharsets.UTF_8).split(System.lineSeparator()), logger.getLevel() @@ -181,7 +172,7 @@ void logFile() throws IOException, InterruptedException, IllegalAccessException // 将文件大小截断至0字节，相当于清空文件内容 fileChannel.truncate(0); } - defaultFileAppender.stop(); + fileAppender.stop(); } } @@ -193,28 +184,28 @@ void cleanExpiredFile() throws IOException, InterruptedException, ExecutionExcep Path cleanExpiredFileDir = LOG_DIR.resolve("cleanExpiredFile"); Files.createDirectories(cleanExpiredFileDir); int logFileRetentionDays = 7; - DefaultFileAppender defaultFileAppender = new DefaultFileAppender( + FileAppender fileAppender = new FileAppender( new DefaultLayout(), cleanExpiredFileDir, logFileRetentionDays ); // make expired log file, here we needn't create file,because the appender will create it. - Path unExpiredFile1 = cleanExpiredFileDir.resolve(DefaultFileAppender.dateToLogFileName(now)); - Path unExpiredFile2 = cleanExpiredFileDir - .resolve(DefaultFileAppender.dateToLogFileName(now.minusDays(logFileRetentionDays - 1))); + Path unExpiredFile1 = cleanExpiredFileDir.resolve(FileAppender.dateToLogFileName(now) + ".log"); + + Path unExpiredFile2 = cleanExpiredFileDir.resolve(FileAppender.dateToLogFileName(now.minusDays(logFileRetentionDays - 1)) + ".log"); Files.createFile(unExpiredFile2); Path expiredFile1 = cleanExpiredFileDir - .resolve(DefaultFileAppender.dateToLogFileName(now.minusDays(logFileRetentionDays))); + .resolve(FileAppender.dateToLogFileName(now.minusDays(logFileRetentionDays)) + ".log"); Files.createFile(expiredFile1); Path expiredFile2 = cleanExpiredFileDir - .resolve(DefaultFileAppender.dateToLogFileName(now.minusDays(logFileRetentionDays + 1))); + .resolve(FileAppender.dateToLogFileName(now.minusDays(logFileRetentionDays + 1)) + ".log"); Files.createFile(expiredFile2); System.out.println("before clean,log files: "); printDirectory(cleanExpiredFileDir); ScheduledFuture future = ReflectUtils - .getMethodWrapper(defaultFileAppender, "triggerCleanTask", true, LocalDateTime.class) + .getMethodWrapper(fileAppender, "triggerCleanTask", true, LocalDateTime.class) .invoke(now); // waiting task finish @@ -238,9 +229,9 @@ void rollingFile() throws IOException, InvocationTargetException, IllegalAccessE Files.createDirectories(rollingFileDir); DefaultLayout defaultLayout = new DefaultLayout(); - DefaultFileAppender defaultFileAppender = new DefaultFileAppender(defaultLayout, rollingFileDir, 0, 0); - defaultFileAppender.start(); - Logger logger = newLogger(LoggerTest.class.getCanonicalName(), defaultFileAppender, INFO); + FileAppender fileAppender = new FileAppender(defaultLayout, rollingFileDir, 0, 0); + fileAppender.start(); + Logger logger = newLogger(LoggerTest.class.getCanonicalName(), fileAppender, INFO); String message = "test"; String log = defaultLayout.format(buildLogEvent(logger, message, new Object[0])); @@ -249,9 +240,9 @@ void rollingFile() throws IOException, InvocationTargetException, IllegalAccessE System.out.println("before files: "); printDirectory(rollingFileDir); // 刚好消息跟文件大小相同 - ReflectUtils.setFieldValue(defaultFileAppender, "logFileSizeBytes", logSize, true); + ReflectUtils.setFieldValue(fileAppender, "logFileSizeBytes", logSize, true); logger.info(message); - waitingForAsyncAppend(defaultFileAppender); + waitingForAsyncAppend(fileAppender); try (Stream s = Files.list(rollingFileDir)) { Assertions.assertEquals(1, s.count()); } @@ -259,9 +250,9 @@ void rollingFile() throws IOException, InvocationTargetException, IllegalAccessE printDirectory(rollingFileDir); // 消息超过文件大小的情况,直接追加在当前文件后 - ReflectUtils.setFieldValue(defaultFileAppender, "logFileSizeBytes", logSize - 1, true); + ReflectUtils.setFieldValue(fileAppender, "logFileSizeBytes", logSize - 1, true); logger.info(message); - waitingForAsyncAppend(defaultFileAppender); + waitingForAsyncAppend(fileAppender); try (Stream s = Files.list(rollingFileDir)) { Assertions.assertEquals(1, s.count()); } @@ -269,25 +260,25 @@ void rollingFile() throws IOException, InvocationTargetException, IllegalAccessE printDirectory(rollingFileDir); // 文件剩余空间不足以填充当前消息 且 消息大小小于文件大小时 roll 到下一个文件 - ReflectUtils.setFieldValue(defaultFileAppender, "logFileSizeBytes", logSize * 2 + 1, true); + ReflectUtils.setFieldValue(fileAppender, "logFileSizeBytes", logSize * 2 + 1, true); logger.info(message); logger.info(message); logger.info(message); - waitingForAsyncAppend(defaultFileAppender); + waitingForAsyncAppend(fileAppender); try (Stream s = Files.list(rollingFileDir)) { Assertions.assertEquals(3, s.count()); } System.out.println("after files: "); printDirectory(rollingFileDir); - defaultFileAppender.stop(); + fileAppender.stop(); } @Test @Order(6) void getLogger() { // test systemProperty set - System.setProperty(LogConstants.SYSTEM_PROPERTY_LOG_LEVEL, TEST_DEFAULT_LEVEL.name()); + System.setProperty(SYSTEM_PROPERTY_LOG_LEVEL, TEST_DEFAULT_LEVEL.name()); Logger byName = LoggerFactory.getLogger(LoggerTest.class.getCanonicalName()); Logger byClass = LoggerFactory.getLogger(LoggerTest.class); @@ -295,29 +286,41 @@ void getLogger() { Assertions.assertSame(byName, byClass); Assertions.assertNotNull(byName); - Assertions.assertEquals(INFO, byName.getLevel()); + Assertions.assertEquals(DEBUG, byName.getLevel()); Assertions.assertEquals(LoggerTest.class.getCanonicalName(), byName.getName()); AppenderCombiner appenderCombiner = getFieldValue(byName, "appender", true); Assertions.assertSame( getFieldValue(LoggerFactory.class, "APPENDER_COMBINER", true), appenderCombiner ); - boolean defaultPrintStreamAppendExists = false; - boolean defaultFileAppendExists = false; + boolean fileAppendExists = false; + boolean consoleAppendExists = false; List> appenderList = getFieldValue(appenderCombiner, "appenderList", true); Assertions.assertNotNull(appenderList); for (Appender appender : appenderList) { - if (appender instanceof DefaultPrintStreamAppender) { - defaultPrintStreamAppendExists = true; + if (appender instanceof FileAppender) { + fileAppendExists = true; } - if (appender instanceof DefaultFileAppender) { - defaultFileAppendExists = true; + if (appender instanceof ConsoleAppender) { + consoleAppendExists = true; } } - boolean logDirPresent = SystemUtils.getSysPropertyPath(LogConstants.SYSTEM_PROPERTY_LOG_DIR).isPresent(); - Assertions.assertTrue(defaultPrintStreamAppendExists); + // LoggerFactory加载比这个类早，所以appenderList一定是空 + boolean logDirPresent = SystemUtils.getSysPropertyPath(SYSTEM_PROPERTY_LOG_DIR).isPresent(); + Assertions.assertFalse(consoleAppendExists); if (logDirPresent){ - Assertions.assertTrue(defaultFileAppendExists); + Assertions.assertFalse(fileAppendExists); + } + } + + private static Logger newLogger(String name, Appender appender, Level level) { + try { + Constructor declaredConstructor = Logger.class.getDeclaredConstructor(String.class, Appender.class, Level.class); + declaredConstructor.setAccessible(true); + return declaredConstructor + .newInstance(name, appender, level); + } catch (Exception e) { + throw new RuntimeException(e); } } @@ -368,7 +371,7 @@ private static void checkLogContents(String[] logs, Level limitLevel) { for (int i = 0; i < allowLevelNum; i++) { // [2024-04-24T16:13:15.027] [main] [INFO] [io.github.artlibs.autotrace4j.LoggerTest] - INFO System.out.printf("check log content pass: %s%n", logs[i]); - String[] logItems = logs[i].split(LogConstants.SPACE); + String[] logItems = logs[i].split(SPACE); Level level = allowLevels.get(i); Assertions.assertEquals(logItems[1], buildItem(Thread.currentThread().getName())); Assertions.assertEquals(logItems[2], buildItem(level.name())); @@ -378,7 +381,7 @@ private static void checkLogContents(String[] logs, Level limitLevel) { } private static String buildItem(String item) { - return LogConstants.LEFT_MIDDLE_BRACKET + item + LogConstants.RIGHT_MIDDLE_BRACKET; + return LEFT_MIDDLE_BRACKET + item + RIGHT_MIDDLE_BRACKET; } private static void printDirectory(Path rollingFileDir) throws IOException {