Rewrite log injection

No longer uses filters, this now rewrites log events using a rewrite policy

The remapping process has been moved to the logger, as otherwise log4j's extra class info would be lost

Author: booky10

CHANGELOG.md

@@ -1,11 +1,15 @@
 ## v1.3.2
 
 - Fix exceptions when remapping lambda methods
+- Added optional remapping of every log message
+- Rewrote internal log injection handling
+  - Now uses Log4j's exception rendering
+  - Removed "MC//" prefix in stacktrace, minecraft classes are now suffixed with "`~[client-intermediary.jar:?]`"
 
 ## v1.3.1
 
 - Added support for quilt mappings below 1.19.2
-  - Now goes down to 1.18.2
+    - Now goes down to 1.18.2
 
 ## v1.3.0
 

README.md

@@ -21,68 +21,68 @@ human-readable.
 <summary><b>Before</b></summary>
 
 > ```
-> [18:04:12] [Render thread/ERROR]: Reported exception thrown!
+> [23:13:08] [Render thread/ERROR]: Reported exception thrown!
 > net.minecraft.class_148: Manually triggered debug crash
->     at net.minecraft.class_309.method_1474(class_309.java:509) ~[client-intermediary.jar:?]
->     at net.minecraft.class_310.method_1574(class_310.java:1955) ~[client-intermediary.jar:?]
->     at net.minecraft.class_310.method_1523(class_310.java:1180) ~[client-intermediary.jar:?]
->     at net.minecraft.class_310.method_1514(class_310.java:801) ~[client-intermediary.jar:?]
->     at net.minecraft.client.main.Main.main(Main.java:237) ~[minecraft-1.19.4-client.jar:?]
->     at net.fabricmc.loader.impl.game.minecraft.MinecraftGameProvider.launch(MinecraftGameProvider.java:462) ~[fabric-loader-0.14.18.jar:?]
->     at net.fabricmc.loader.impl.launch.knot.Knot.launch(Knot.java:74) ~[fabric-loader-0.14.18.jar:?]
->     at net.fabricmc.loader.impl.launch.knot.KnotClient.main(KnotClient.java:23) ~[fabric-loader-0.14.18.jar:?]
->     at org.prismlauncher.launcher.impl.StandardLauncher.launch(StandardLauncher.java:88) ~[NewLaunch.jar:?]
->     at org.prismlauncher.EntryPoint.listen(EntryPoint.java:126) ~[NewLaunch.jar:?]
->     at org.prismlauncher.EntryPoint.main(EntryPoint.java:71) ~[NewLaunch.jar:?]
+>          at net.minecraft.class_309.method_1474(class_309.java:509) ~[client-intermediary.jar:?]
+>          at net.minecraft.class_310.method_1574(class_310.java:1955) ~[client-intermediary.jar:?]
+>          at net.minecraft.class_310.method_1523(class_310.java:1180) ~[client-intermediary.jar:?]
+>          at net.minecraft.class_310.method_1514(class_310.java:801) ~[client-intermediary.jar:?]
+>          at net.minecraft.client.main.Main.main(Main.java:237) ~[minecraft-1.19.4-client.jar:?]
+>          at net.fabricmc.loader.impl.game.minecraft.MinecraftGameProvider.launch(MinecraftGameProvider.java:462) ~[fabric-loader-0.14.18.jar:?]
+>          at net.fabricmc.loader.impl.launch.knot.Knot.launch(Knot.java:74) ~[fabric-loader-0.14.18.jar:?]
+>          at net.fabricmc.loader.impl.launch.knot.KnotClient.main(KnotClient.java:23) ~[fabric-loader-0.14.18.jar:?]
+>          at org.prismlauncher.launcher.impl.StandardLauncher.launch(StandardLauncher.java:88) ~[NewLaunch.jar:?]
+>          at org.prismlauncher.EntryPoint.listen(EntryPoint.java:126) ~[NewLaunch.jar:?]
+>          at org.prismlauncher.EntryPoint.main(EntryPoint.java:71) ~[NewLaunch.jar:?]
 > Caused by: java.lang.Throwable: Manually triggered debug crash
->     at net.minecraft.class_309.method_1474(class_309.java:506) ~[client-intermediary.jar:?]
->     ... 10 more
+>          at net.minecraft.class_309.method_1474(class_309.java:506) ~[client-intermediary.jar:?]
+>          ... 10 more
 > ```
 
 </details>
 <details>
 <summary><b>After (yarn/quilt mappings)</b></summary>
 
 > ```
-> [18:02:00] [Render thread/ERROR]: Reported exception thrown!
-> [18:02:00] [Render thread/ERROR]: net.minecraft.util.crash.CrashException: Manually triggered debug crash
->     at MC//net.minecraft.client.Keyboard.pollDebugCrash(Keyboard.java:509)
->     at MC//net.minecraft.client.MinecraftClient.tick(MinecraftClient.java:1955)
->     at MC//net.minecraft.client.MinecraftClient.render(MinecraftClient.java:1180)
->     at MC//net.minecraft.client.MinecraftClient.run(MinecraftClient.java:801)
->     at net.minecraft.client.main.Main.main(Main.java:237)
->     at net.fabricmc.loader.impl.game.minecraft.MinecraftGameProvider.launch(MinecraftGameProvider.java:462)
->     at net.fabricmc.loader.impl.launch.knot.Knot.launch(Knot.java:74)
->     at net.fabricmc.loader.impl.launch.knot.KnotClient.main(KnotClient.java:23)
->     at org.prismlauncher.launcher.impl.StandardLauncher.launch(StandardLauncher.java:88)
->     at org.prismlauncher.EntryPoint.listen(EntryPoint.java:126)
->     at org.prismlauncher.EntryPoint.main(EntryPoint.java:71)
+> [23:11:25] [Render thread/ERROR]: Reported exception thrown!
+> net.minecraft.util.crash.CrashException: Manually triggered debug crash
+>          at net.minecraft.client.Keyboard.pollDebugCrash(Keyboard.java:509) ~[client-intermediary.jar:?]
+>          at net.minecraft.client.MinecraftClient.tick(MinecraftClient.java:1955) ~[client-intermediary.jar:?]
+>          at net.minecraft.client.MinecraftClient.render(MinecraftClient.java:1180) ~[client-intermediary.jar:?]
+>          at net.minecraft.client.MinecraftClient.run(MinecraftClient.java:801) ~[client-intermediary.jar:?]
+>          at net.minecraft.client.main.Main.main(Main.java:237) ~[minecraft-1.19.4-client.jar:?]
+>          at net.fabricmc.loader.impl.game.minecraft.MinecraftGameProvider.launch(MinecraftGameProvider.java:462) ~[fabric-loader-0.14.18.jar:?]
+>          at net.fabricmc.loader.impl.launch.knot.Knot.launch(Knot.java:74) ~[fabric-loader-0.14.18.jar:?]
+>          at net.fabricmc.loader.impl.launch.knot.KnotClient.main(KnotClient.java:23) ~[fabric-loader-0.14.18.jar:?]
+>          at org.prismlauncher.launcher.impl.StandardLauncher.launch(StandardLauncher.java:88) ~[NewLaunch.jar:?]
+>          at org.prismlauncher.EntryPoint.listen(EntryPoint.java:126) ~[NewLaunch.jar:?]
+>          at org.prismlauncher.EntryPoint.main(EntryPoint.java:71) ~[NewLaunch.jar:?]
 > Caused by: java.lang.Throwable: Manually triggered debug crash
->     at MC//net.minecraft.client.Keyboard.pollDebugCrash(Keyboard.java:506)
->     ... 10 more
+>          at net.minecraft.client.Keyboard.pollDebugCrash(Keyboard.java:506) ~[client-intermediary.jar:?]
+>          ... 10 more
 > ```
 
 </details>
 <details>
 <summary><b>After (mojang mappings)</b></summary>
 
 > ```
-> [17:52:01] [Render thread/ERROR]: Reported exception thrown!
-> [17:52:01] [Render thread/ERROR]: net.minecraft.ReportedException: Manually triggered debug crash
->     at MC//net.minecraft.client.KeyboardHandler.tick(KeyboardHandler.java:509)
->     at MC//net.minecraft.client.Minecraft.tick(Minecraft.java:1955)
->     at MC//net.minecraft.client.Minecraft.runTick(Minecraft.java:1180)
->     at MC//net.minecraft.client.Minecraft.run(Minecraft.java:801)
->     at net.minecraft.client.main.Main.main(Main.java:237)
->     at net.fabricmc.loader.impl.game.minecraft.MinecraftGameProvider.launch(MinecraftGameProvider.java:462)
->     at net.fabricmc.loader.impl.launch.knot.Knot.launch(Knot.java:74)
->     at net.fabricmc.loader.impl.launch.knot.KnotClient.main(KnotClient.java:23)
->     at org.prismlauncher.launcher.impl.StandardLauncher.launch(StandardLauncher.java:88)
->     at org.prismlauncher.EntryPoint.listen(EntryPoint.java:126)
->     at org.prismlauncher.EntryPoint.main(EntryPoint.java:71)
+> [23:04:12] [Render thread/ERROR]: Reported exception thrown!
+> net.minecraft.ReportedException: Manually triggered debug crash
+>          at net.minecraft.client.KeyboardHandler.tick(KeyboardHandler.java:509) ~[client-intermediary.jar:?]
+>          at net.minecraft.client.Minecraft.tick(Minecraft.java:1955) ~[client-intermediary.jar:?]
+>          at net.minecraft.client.Minecraft.runTick(Minecraft.java:1180) ~[client-intermediary.jar:?]
+>          at net.minecraft.client.Minecraft.run(Minecraft.java:801) ~[client-intermediary.jar:?]
+>          at net.minecraft.client.main.Main.main(Main.java:237) ~[minecraft-1.19.4-client.jar:?]
+>          at net.fabricmc.loader.impl.game.minecraft.MinecraftGameProvider.launch(MinecraftGameProvider.java:462) ~[fabric-loader-0.14.18.jar:?]
+>          at net.fabricmc.loader.impl.launch.knot.Knot.launch(Knot.java:74) ~[fabric-loader-0.14.18.jar:?]
+>          at net.fabricmc.loader.impl.launch.knot.KnotClient.main(KnotClient.java:23) ~[fabric-loader-0.14.18.jar:?]
+>          at org.prismlauncher.launcher.impl.StandardLauncher.launch(StandardLauncher.java:88) ~[NewLaunch.jar:?]
+>          at org.prismlauncher.EntryPoint.listen(EntryPoint.java:126) ~[NewLaunch.jar:?]
+>          at org.prismlauncher.EntryPoint.main(EntryPoint.java:71) ~[NewLaunch.jar:?]
 > Caused by: java.lang.Throwable: Manually triggered debug crash
->     at MC//net.minecraft.client.KeyboardHandler.tick(KeyboardHandler.java:506)
->     ... 10 more
+>          at net.minecraft.client.KeyboardHandler.tick(KeyboardHandler.java:506) ~[client-intermediary.jar:?]
+>          ... 10 more
 > ```
 
 </details>

src/main/java/dev/booky/stackdeobf/StackDeobfMod.java

@@ -3,7 +3,8 @@
 
 import dev.booky.stackdeobf.config.StackDeobfConfig;
 import dev.booky.stackdeobf.mappings.CachedMappings;
-import dev.booky.stackdeobf.mappings.RemappingUtil;
+import dev.booky.stackdeobf.util.CompatUtil;
+import dev.booky.stackdeobf.util.RemappingRewritePolicy;
 import net.fabricmc.api.ModInitializer;
 import net.fabricmc.loader.api.FabricLoader;
 import org.apache.logging.log4j.LogManager;
@@ -18,7 +19,9 @@ public void onInitialize() {
         StackDeobfConfig config = this.loadConfig();
 
         if (config.hasLogInjectEnabled()) {
-            RemappingUtil.injectLogFilter((Logger) LogManager.getRootLogger(), config.shouldRewriteEveryLogMessage());
+            CompatUtil.LOGGER.info("Injecting into root logger...");
+            RemappingRewritePolicy policy = new RemappingRewritePolicy(config);
+            policy.inject((Logger) LogManager.getRootLogger());
         }
 
         CachedMappings.init(config.getMappingProvider());

src/main/java/dev/booky/stackdeobf/mappings/RemappedThrowable.java

@@ -1,15 +1,25 @@
 package dev.booky.stackdeobf.mappings;
 // Created by booky10 in StackDeobfuscator (18:03 20.03.23)
 
-class RemappedThrowable extends Throwable {
+import org.jetbrains.annotations.ApiStatus;
 
+@ApiStatus.Internal
+public class RemappedThrowable extends Throwable {
+
+    private final Throwable original;
     private final String className;
 
-    public RemappedThrowable(String message, Throwable cause, String className) {
+    public RemappedThrowable(String message, Throwable cause,
+                             Throwable original, String className) {
         super(message, cause);
+        this.original = original;
         this.className = className;
     }
 
+    public Throwable getOriginal() {
+        return this.original;
+    }
+
     public String getClassName() {
         return this.className;
     }

src/main/java/dev/booky/stackdeobf/mappings/RemappingUtil.java

@@ -1,13 +1,6 @@
 package dev.booky.stackdeobf.mappings;
 // Created by booky10 in StackDeobfuscator (17:43 17.12.22)
 
-import dev.booky.stackdeobf.util.CompatUtil;
-import org.apache.logging.log4j.core.LogEvent;
-import org.apache.logging.log4j.core.filter.AbstractFilter;
-
-import java.io.IOException;
-import java.io.PrintWriter;
-import java.io.StringWriter;
 import java.util.regex.Matcher;
 import java.util.regex.Pattern;
 
@@ -20,57 +13,7 @@ public final class RemappingUtil {
     private RemappingUtil() {
     }
 
-    public static void injectLogFilter(org.apache.logging.log4j.core.Logger logger, boolean rewriteMessages) {
-        CompatUtil.LOGGER.info("Injecting into root logger...");
-        logger.addFilter(new AbstractFilter() {
-            @Override
-            public Result filter(LogEvent event) {
-                // TODO: this is a horribly hacky way to rewrite messages, find something better
-
-                if (event.getThrown() == null) {
-                    if (!rewriteMessages) {
-                        return Result.NEUTRAL;
-                    }
-
-                    String message = event.getMessage().getFormattedMessage();
-                    String remappedMessage = RemappingUtil.remapString(message);
-
-                    if (message.equals(remappedMessage)) {
-                        // didn't change anything, continue
-                        return Result.NEUTRAL;
-                    }
-
-                    logger.logIfEnabled(event.getLoggerFqcn(), event.getLevel(), event.getMarker(), remappedMessage);
-
-                    // cancel the underlying event, this needs
-                    // to be rewritten
-                    return Result.DENY;
-                }
-
-                // we need to manually print out the stacktrace, because
-                // log4j also builds it manually, resulting
-                // in every logged exception being a "RemappedThrowable"
-                try (StringWriter strWriter = new StringWriter()) {
-                    try (PrintWriter writer = new PrintWriter(strWriter)) {
-                        RemappingUtil.remapThrowable(event.getThrown()).printStackTrace(writer);
-                    }
-
-                    // this message doesn't need to be remapped if every message should be remapped,
-                    // as this is handled by the above logic already
-                    logger.logIfEnabled(event.getLoggerFqcn(), event.getLevel(), event.getMarker(), event.getMessage(), null);
-
-                    logger.logIfEnabled(event.getLoggerFqcn(), event.getLevel(), event.getMarker(), strWriter.toString());
-                } catch (IOException exception) {
-                    throw new RuntimeException(exception);
-                }
-
-                // cancel the underlying log event
-                return Result.DENY;
-            }
-        });
-    }
-
-    private static String remapClasses(String string) {
+    public static String remapClasses(String string) {
         return CLASS_PATTERN.matcher(string).replaceAll(result -> {
             int classId = Integer.parseInt(result.group(2));
             String className = CachedMappings.remapClass(classId);
@@ -92,15 +35,15 @@ private static String remapClasses(String string) {
         });
     }
 
-    private static String remapMethods(String string) {
+    public static String remapMethods(String string) {
         return METHOD_PATTERN.matcher(string).replaceAll(result -> {
             int methodId = Integer.parseInt(result.group(1));
             String methodName = CachedMappings.remapMethod(methodId);
             return methodName == null ? result.group() : Matcher.quoteReplacement(methodName);
         });
     }
 
-    private static String remapFields(String string) {
+    public static String remapFields(String string) {
         return FIELD_PATTERN.matcher(string).replaceAll(result -> {
             int fieldId = Integer.parseInt(result.group(1));
             String fieldName = CachedMappings.remapField(fieldId);
@@ -147,7 +90,7 @@ public static Throwable remapThrowable(Throwable throwable) {
             throwableName = remapClasses(throwableName);
         }
 
-        Throwable remapped = new RemappedThrowable(message, cause, throwableName);
+        Throwable remapped = new RemappedThrowable(message, cause, throwable, throwableName);
         remapped.setStackTrace(stackTrace);
         for (Throwable suppressed : throwable.getSuppressed()) {
             remapped.addSuppressed(remapThrowable(suppressed));
@@ -179,7 +122,16 @@ public static StackTraceElement remapStackTraceElement(StackTraceElement element
             methodName = remapMethods(methodName);
         }
 
-        return new StackTraceElement(remappedClass ? "MC" : null, element.getModuleName(), element.getModuleVersion(),
+        String classLoaderName = element.getClassLoaderName();
+        if (remappedClass) {
+            if (classLoaderName == null) {
+                classLoaderName = "MC";
+            } else {
+                classLoaderName += "//MC";
+            }
+        }
+
+        return new StackTraceElement(classLoaderName, element.getModuleName(), element.getModuleVersion(),
                 className, methodName, fileName, element.getLineNumber());
     }
 }

src/main/java/dev/booky/stackdeobf/mixin/CrashReportMixin.java

@@ -1,6 +1,7 @@
 package dev.booky.stackdeobf.mixin;
 // Created by booky10 in StackDeobfuscator (18:35 20.03.23)
 
+import dev.booky.stackdeobf.mappings.RemappedThrowable;
 import dev.booky.stackdeobf.mappings.RemappingUtil;
 import net.minecraft.CrashReport;
 import org.spongepowered.asm.mixin.Final;
@@ -10,6 +11,7 @@
 import org.spongepowered.asm.mixin.injection.At;
 import org.spongepowered.asm.mixin.injection.Inject;
 import org.spongepowered.asm.mixin.injection.callback.CallbackInfo;
+import org.spongepowered.asm.mixin.injection.callback.CallbackInfoReturnable;
 
 @Mixin(CrashReport.class)
 public class CrashReportMixin {
@@ -23,4 +25,20 @@ public class CrashReportMixin {
     public void postInit(String title, Throwable throwable, CallbackInfo ci) {
         this.exception = RemappingUtil.remapThrowable(throwable);
     }
+
+    @Inject(
+            method = "getException",
+            at = @At("HEAD"),
+            cancellable = true
+    )
+    public void preExceptionGet(CallbackInfoReturnable<Throwable> cir) {
+        // redirect calls to getException to the original, unmapped Throwable
+        //
+        // this method is called in the ReportedException, which
+        // caused the "RemappedThrowable" name to show up in the logger
+
+        if (this.exception instanceof RemappedThrowable remapped) {
+            cir.setReturnValue(remapped.getOriginal());
+        }
+    }
 }

src/main/java/dev/booky/stackdeobf/util/Log4jRemapUtil.java

@@ -0,0 +1,56 @@
+package dev.booky.stackdeobf.util;
+// Created by booky10 in StackDeobfuscator (22:33 14.04.23)
+
+import dev.booky.stackdeobf.mappings.RemappingUtil;
+import org.apache.logging.log4j.core.impl.ExtendedStackTraceElement;
+import org.apache.logging.log4j.core.impl.ThrowableProxy;
+
+import java.lang.reflect.Field;
+
+final class Log4jRemapUtil {
+
+    private static final Field PROXY_NAME = getField(ThrowableProxy.class, "name");
+    private static final Field PROXY_MESSAGE = getField(ThrowableProxy.class, "message");
+    private static final Field PROXY_LOCALIZED_MESSAGE = getField(ThrowableProxy.class, "localizedMessage");
+    private static final Field EXT_STACK_ELEMENT = getField(ExtendedStackTraceElement.class, "stackTraceElement");
+
+    private static Field getField(Class<?> clazz, String name) {
+        try {
+            Field field = clazz.getDeclaredField(name);
+            field.setAccessible(true);
+            return field;
+        } catch (ReflectiveOperationException exception) {
+            throw new RuntimeException(exception);
+        }
+    }
+
+    static void remapThrowableProxy(ThrowableProxy proxy) throws IllegalAccessException {
+        // remap throwable classname
+        if (proxy.getName() != null && proxy.getName().startsWith("net.minecraft.class_")) {
+            PROXY_NAME.set(proxy, RemappingUtil.remapClasses(proxy.getName()));
+        }
+
+        // remap throwable message
+        if (proxy.getMessage() != null) {
+            PROXY_MESSAGE.set(proxy, RemappingUtil.remapString(proxy.getMessage()));
+        }
+        if (proxy.getLocalizedMessage() != null) {
+            PROXY_LOCALIZED_MESSAGE.set(proxy, RemappingUtil.remapString(proxy.getLocalizedMessage()));
+        }
+
+        // remap throwable stack trace
+        for (ExtendedStackTraceElement extElement : proxy.getExtendedStackTrace()) {
+            StackTraceElement element = extElement.getStackTraceElement();
+            element = RemappingUtil.remapStackTraceElement(element);
+            EXT_STACK_ELEMENT.set(extElement, element);
+        }
+
+        // remap cause + suppressed throwables
+        if (proxy.getCauseProxy() != null) {
+            remapThrowableProxy(proxy.getCauseProxy());
+        }
+        for (ThrowableProxy suppressed : proxy.getSuppressedProxies()) {
+            remapThrowableProxy(suppressed);
+        }
+    }
+}