feat: 为脚本添加日志记录器.

- 增加 ScriptLoggerFactory, 通过 CGLIB 为 Logger 设置动态代理, 在记录日志时隐式添加 marker, 配合日志配置调整脚本日志输出, 以解决脚本无法将日志记录到日志文件中的问题. - 调整 Trigger 日志记录器获取方式, 以解决脚本可能误用 Trigger 日志记录器的问题. - 适当调整了部分包的日志记录级别.
2025-04-29 14:17:34 +00:00 · 2021-09-02 14:30:50 +08:00 · 2021-09-02 14:30:50 +08:00 · 8658104f7f
commit 8658104f7f
parent 2cd679bcaf
9 changed files with 258 additions and 22 deletions
--- a/build.gradle
+++ b/build.gradle
@ -32,6 +32,8 @@ dependencies {
    implementation "org.bouncycastle:bcpg-jdk15on:${bouncyCastleVer}"
    implementation "org.bouncycastle:bcpkix-jdk15on:${bouncyCastleVer}"

+    implementation 'cglib:cglib:3.3.0'
+
    implementation "net.i2p.crypto:eddsa:0.3.0"

    implementation 'org.codehaus.groovy:groovy-all:3.0.7'
--- a/src/main/java/net/lamgc/oracle/sentry/common/logging/LevelRangeFilter.java
+++ b/src/main/java/net/lamgc/oracle/sentry/common/logging/LevelRangeFilter.java
@ -0,0 +1,43 @@
+package net.lamgc.oracle.sentry.common.logging;
+
+import ch.qos.logback.classic.Level;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.filter.Filter;
+import ch.qos.logback.core.spi.FilterReply;
+
+/**
+ * 级别范围过滤器.
+ * @author LamGC
+ */
+public class LevelRangeFilter extends Filter<ILoggingEvent> {
+
+    private Level maxLevel;
+    private Level minLevel;
+
+    @Override
+    public FilterReply decide(ILoggingEvent event) {
+        int level = event.getLevel().levelInt;
+        if (level > maxLevel.levelInt || level < minLevel.levelInt) {
+            return FilterReply.DENY;
+        }
+        return FilterReply.NEUTRAL;
+    }
+
+    public void setMaxLevel(String maxLevel) {
+        this.maxLevel = Level.toLevel(maxLevel);
+    }
+
+    public void setMinLevel(String minLevel) {
+        this.minLevel = Level.toLevel(minLevel);
+    }
+
+    @Override
+    public void start() {
+        if (maxLevel != null && minLevel != null) {
+            if (maxLevel.levelInt < minLevel.levelInt) {
+                throw new IllegalArgumentException("The maximum level cannot be less than the minimum level.");
+            }
+            super.start();
+        }
+    }
+}
--- a/src/main/java/net/lamgc/oracle/sentry/common/logging/MarkerFilter.java
+++ b/src/main/java/net/lamgc/oracle/sentry/common/logging/MarkerFilter.java
@ -0,0 +1,39 @@
+package net.lamgc.oracle.sentry.common.logging;
+
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.filter.Filter;
+import ch.qos.logback.core.spi.FilterReply;
+
+/**
+ * @author LamGC
+ */
+public class MarkerFilter extends Filter<ILoggingEvent> {
+
+    private String markerName;
+    private FilterReply onMatch = FilterReply.NEUTRAL;
+    private FilterReply onMismatch = FilterReply.DENY;
+
+    @Override
+    public FilterReply decide(ILoggingEvent event) {
+        return event.getMarker() != null && event.getMarker().getName().equals(markerName) ? onMatch : onMismatch;
+    }
+
+    public void setMarkerName(String markerName) {
+        this.markerName = markerName;
+    }
+
+    public void setOnMatch(String onMatch) {
+        this.onMatch = FilterReply.valueOf(onMatch);
+    }
+
+    public void setOnMismatch(String onMismatch) {
+        this.onMismatch = FilterReply.valueOf(onMismatch);
+    }
+
+    @Override
+    public void start() {
+        if (markerName != null && onMatch != null && onMismatch != null) {
+            super.start();
+        }
+    }
+}
--- a/src/main/java/net/lamgc/oracle/sentry/common/logging/NoMarkerFilter.java
+++ b/src/main/java/net/lamgc/oracle/sentry/common/logging/NoMarkerFilter.java
@ -0,0 +1,15 @@
+package net.lamgc.oracle.sentry.common.logging;
+
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.filter.Filter;
+import ch.qos.logback.core.spi.FilterReply;
+
+/**
+ * @author LamGC
+ */
+public class NoMarkerFilter extends Filter<ILoggingEvent> {
+    @Override
+    public FilterReply decide(ILoggingEvent event) {
+        return event.getMarker() != null ? FilterReply.DENY : FilterReply.NEUTRAL;
+    }
+}
--- a/src/main/java/net/lamgc/oracle/sentry/script/ScriptComponents.java
+++ b/src/main/java/net/lamgc/oracle/sentry/script/ScriptComponents.java
@ -11,7 +11,8 @@ import net.lamgc.oracle.sentry.script.tools.http.ScriptHttpClient;
 */
 public final record ScriptComponents(
        ScriptHttpClient HTTP,
-        ComputeInstanceManager InstanceManager
+        ComputeInstanceManager InstanceManager,
+        ScriptLoggerFactory loggerFactory
 ) {

 }
--- a/src/main/java/net/lamgc/oracle/sentry/script/ScriptLoggerFactory.java
+++ b/src/main/java/net/lamgc/oracle/sentry/script/ScriptLoggerFactory.java
@ -0,0 +1,79 @@
+package net.lamgc.oracle.sentry.script;
+
+import net.sf.cglib.proxy.Enhancer;
+import net.sf.cglib.proxy.MethodInterceptor;
+import net.sf.cglib.proxy.MethodProxy;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
+import org.slf4j.Marker;
+import org.slf4j.MarkerFactory;
+
+import java.lang.reflect.Method;
+import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.List;
+import java.util.Set;
+
+/**
+ * 脚本日志记录器工厂.
+ * <p> 通过 CGLIB 无缝为脚本设置 {@link Marker} 以将脚本日志输出到特定文件中.
+ * @author LamGC
+ */
+public class ScriptLoggerFactory implements ScriptComponentFactory<Logger> {
+
+    public final static Marker SCRIPT_MARKER = MarkerFactory.getMarker("Script");
+
+    @Override
+    public Logger getInstance(ScriptInfo info) {
+        Logger realLogger = LoggerFactory.getLogger(info.getGroup() + ":" + info.getName());
+        Enhancer enhancer = new Enhancer();
+        enhancer.setSuperclass(Logger.class);
+        enhancer.setCallback(new LoggerProxyImpl(realLogger));
+        return (Logger) enhancer.create();
+    }
+
+    @Override
+    public String getPropertyName() {
+        return "Log";
+    }
+
+    private static class LoggerProxyImpl implements MethodInterceptor {
+
+        private final static Set<String> PROXY_METHOD_NAMES = Set.of(
+                "trace", "debug", "info", "warn", "error",
+                "isTraceEnabled",
+                "isDebugEnabled",
+                "isInfoEnabled",
+                "isWarnEnabled",
+                "isErrorEnabled"
+        );
+
+        private final Logger targetLog;
+        private final Class<? extends Logger> logClass;
+
+        public LoggerProxyImpl(Logger targetLog) {
+            this.targetLog = targetLog;
+            logClass = targetLog.getClass();
+        }
+
+        @Override
+        public Object intercept(Object obj, Method method, Object[] args, MethodProxy proxy) throws Throwable {
+            if (PROXY_METHOD_NAMES.contains(method.getName())) {
+                Class<?>[] types = method.getParameterTypes();
+                List<Class<?>> typeList = new ArrayList<>(Arrays.asList(types));
+                typeList.add(0, Marker.class);
+                if (types.length != 0 && !Marker.class.isAssignableFrom(types[0])) {
+                    Class<?>[] realMethodParamTypes = typeList.toArray(new Class<?>[0]);
+                    Method realMethod = logClass.getDeclaredMethod(method.getName(), realMethodParamTypes);
+                    List<Object> paramList = new ArrayList<>(Arrays.asList(args));
+                    paramList.add(0, SCRIPT_MARKER);
+                    Object[] params = paramList.toArray(new Object[0]);
+                    realMethod.invoke(targetLog, params);
+                    return null;
+                }
+            }
+            return proxy.invoke(targetLog, args);
+        }
+    }
+
+}
--- a/src/main/java/net/lamgc/oracle/sentry/script/groovy/trigger/OnceTrigger.java
+++ b/src/main/java/net/lamgc/oracle/sentry/script/groovy/trigger/OnceTrigger.java
@ -2,7 +2,6 @@ package net.lamgc.oracle.sentry.script.groovy.trigger;

 import com.google.common.util.concurrent.ThreadFactoryBuilder;
 import groovy.lang.Closure;
-import org.slf4j.Logger;
 import org.slf4j.LoggerFactory;

 import java.util.concurrent.ExecutorService;
@ -14,13 +13,12 @@ import java.util.concurrent.Executors;
 */
@TriggerName("once")
 public class OnceTrigger implements GroovyTrigger {
-
-    private final static Logger log = LoggerFactory.getLogger(OnceTrigger.class);
    private final static ExecutorService EXECUTOR = Executors.newFixedThreadPool(
            Runtime.getRuntime().availableProcessors(),
            new ThreadFactoryBuilder()
                    .setNameFormat("GroovyOnceExec-%d")
-                    .setUncaughtExceptionHandler((t, e) -> log.error("脚本执行时发生未捕获异常.", e))
+                    .setUncaughtExceptionHandler((t, e) -> LoggerFactory.getLogger(OnceTrigger.class)
+                            .error("脚本执行时发生未捕获异常.", e))
            .build());

    @Override
--- a/src/main/java/net/lamgc/oracle/sentry/script/groovy/trigger/TimerTrigger.java
+++ b/src/main/java/net/lamgc/oracle/sentry/script/groovy/trigger/TimerTrigger.java
@ -17,16 +17,13 @@ import java.util.concurrent.ScheduledFuture;
@TriggerName("timer")
 public class TimerTrigger implements GroovyTrigger {

-    private final static Logger log = LoggerFactory.getLogger(TimerTrigger.class);
-
-    private CronTrigger trigger;
    private final static ThreadPoolTaskScheduler SCHEDULER = new ThreadPoolTaskScheduler();
    static {
        SCHEDULER.setPoolSize(Runtime.getRuntime().availableProcessors());
        SCHEDULER.setThreadFactory(new ThreadFactoryBuilder()
                .setNameFormat("Groovy-TimerTrigger-%d")
                .build());
-        SCHEDULER.setErrorHandler(t -> log.error("脚本执行时发生异常.", t));
+        SCHEDULER.setErrorHandler(t -> getLog().error("脚本执行时发生异常.", t));
        SCHEDULER.initialize();
    }

@ -45,21 +42,26 @@ public class TimerTrigger implements GroovyTrigger {
    }

    @Override
-    public void run(Closure<?> runnable) {
+    public synchronized void run(Closure<?> runnable) {
+        if (future != null) {
+            getLog().warn("脚本存在多个 run 代码块, 已忽略.");
+            return;
+        }
+
        if (trigger == null) {
-            if (!log.isDebugEnabled()) {
-                log.warn("脚本尚未设置 Cron 时间表达式, 任务将不会执行(堆栈信息请检查调试级别日志).");
+            if (!getLog().isDebugEnabled()) {
+                getLog().warn("脚本尚未设置 Cron 时间表达式, 任务将不会执行(堆栈信息请检查调试级别日志).");
            } else {
-                log.warn("{} - 脚本尚未设置 Cron 时间表达式, 任务将不会执行(堆栈信息请检查调试级别日志).", this);
-                log.warn("{} - 脚本尚未设置 Cron 时间表达式, 任务将不会执行.\n{}", this, Throwables.getStackTraceAsString(new Exception()));
+                getLog().warn("{} - 脚本尚未设置 Cron 时间表达式, 任务将不会执行(堆栈信息请检查调试级别日志).", this);
+                getLog().warn("{} - 脚本尚未设置 Cron 时间表达式, 任务将不会执行.\n{}", this, Throwables.getStackTraceAsString(new Exception()));
            }
            return;
        } else if (runnable == null) {
-            if (!log.isDebugEnabled()) {
-                log.warn("脚本尚未设置 Cron 时间表达式, 任务将不会执行(堆栈信息请检查调试级别日志).");
+            if (!getLog().isDebugEnabled()) {
+                getLog().warn("脚本尚未设置 Cron 时间表达式, 任务将不会执行(堆栈信息请检查调试级别日志).");
            } else {
-                log.warn("{} - 脚本尚未设置任务动作, 任务将不会执行(堆栈信息请检查调试级别日志).", this);
-                log.warn("{} - 脚本尚未设置任务动作, 任务将不会执行.\n{}", this, Throwables.getStackTraceAsString(new Exception()));
+                getLog().warn("{} - 脚本尚未设置任务动作, 任务将不会执行(堆栈信息请检查调试级别日志).", this);
+                getLog().warn("{} - 脚本尚未设置任务动作, 任务将不会执行.\n{}", this, Throwables.getStackTraceAsString(new Exception()));
            }
            return;
        }
@ -73,6 +75,10 @@ public class TimerTrigger implements GroovyTrigger {
            future.cancel(false);
        }
    }
+    
+    private static Logger getLog() {
+        return LoggerFactory.getLogger(TimerTrigger.class);
+    }

    private static class TimerTaskRunnable implements Runnable {

--- a/src/main/resources/logback.xml
+++ b/src/main/resources/logback.xml
@ -2,10 +2,10 @@
 <configuration debug="false">
    <appender name="stdout" class="ch.qos.logback.core.ConsoleAppender">
        <target>System.out</target>
-        <filter class="ch.qos.logback.classic.filter.LevelFilter">
-            <level>INFO</level>
-            <onMatch>ACCEPT</onMatch>
-            <onMismatch>DENY</onMismatch>
+        <filter class="net.lamgc.oracle.sentry.common.logging.NoMarkerFilter"/>
+        <filter class="net.lamgc.oracle.sentry.common.logging.LevelRangeFilter">
+            <minLevel>DEBUG</minLevel>
+            <maxLevel>INFO</maxLevel>
        </filter>
        <encoder>
            <pattern>[%d{HH:mm:ss.SSS} %5level][%logger][%thread]: %msg%n</pattern>
@ -13,6 +13,7 @@
    </appender>
    <appender name="stderr" class="ch.qos.logback.core.ConsoleAppender">
        <target>System.err</target>
+        <filter class="net.lamgc.oracle.sentry.common.logging.NoMarkerFilter"/>
        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
            <level>WARN</level>
        </filter>
@ -23,6 +24,7 @@

    <appender name="logFile" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>./logs/latest.log</file>
+        <filter class="net.lamgc.oracle.sentry.common.logging.NoMarkerFilter"/>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>TRACE</level>
            <onMatch>DENY</onMatch>
@ -37,11 +39,62 @@
        </rollingPolicy>
    </appender>

+    <appender name="stdout_script" class="ch.qos.logback.core.ConsoleAppender">
+        <target>System.out</target>
+        <filter class="net.lamgc.oracle.sentry.common.logging.MarkerFilter">
+            <markerName>Script</markerName>
+        </filter>
+        <filter class="net.lamgc.oracle.sentry.common.logging.LevelRangeFilter">
+            <minLevel>DEBUG</minLevel>
+            <maxLevel>INFO</maxLevel>
+        </filter>
+        <encoder>
+            <pattern>[%d{HH:mm:ss.SSS} %5level][Script][%logger]: %msg%n</pattern>
+        </encoder>
+    </appender>
+    <appender name="stderr_script" class="ch.qos.logback.core.ConsoleAppender">
+        <target>System.err</target>
+        <filter class="net.lamgc.oracle.sentry.common.logging.MarkerFilter">
+            <markerName>Script</markerName>
+        </filter>
+        <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
+            <level>WARN</level>
+        </filter>
+        <encoder>
+            <pattern>[%d{HH:mm:ss.SSS} %5level][Script][%logger]: %msg%n</pattern>
+        </encoder>
+    </appender>
+
+    <appender name="logFile_script" class="ch.qos.logback.core.rolling.RollingFileAppender">
+        <file>./logs/latest-script.log</file>
+        <filter class="net.lamgc.oracle.sentry.common.logging.MarkerFilter">
+            <markerName>Script</markerName>
+        </filter>
+        <filter class="ch.qos.logback.classic.filter.LevelFilter">
+            <level>TRACE</level>
+            <onMatch>DENY</onMatch>
+            <onMismatch>ACCEPT</onMismatch>
+        </filter>
+        <encoder>
+            <pattern>[%d{HH:mm:ss.SSS} %5level][Script][%logger]: %msg%n</pattern>
+        </encoder>
+        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
+            <fileNamePattern>./logs/run-script-%d{yyyy-MM-dd}.log</fileNamePattern>
+            <maxHistory>30</maxHistory>
+        </rollingPolicy>
+    </appender>
+
    <logger name="com.oracle.bmc" level="WARN"/>
+    <logger name="org.springframework" level="INFO"/>
+    <logger name="org.apache.http" level="INFO"/>
    <logger name="com.oracle.bmc.http.ApacheConfigurator" level="ERROR"/>
    <root>
        <appender-ref ref="stdout" />
        <appender-ref ref="stderr" />
        <appender-ref ref="logFile" />
+
+        <appender-ref ref="stdout_script" />
+        <appender-ref ref="stderr_script" />
+        <appender-ref ref="logFile_script" />
    </root>
 </configuration>