Add logging with klog (#46)

- Introduce package exclusion mechanism to prevent klog classes from being loaded in different defining ClassLoaders (it is normal that there are more initiating loaders at play, but here this means reinitialization of the log files) - Let Mixin log through Weave - Remove dead code Squashed commit of the following: commit 052502e Merge: b3e9a84 61fccf2 Author: killian <[email protected]> Date: Wed May 15 19:11:39 2024 +0200 Merge branch 'master' into feat/logging commit b3e9a84 Author: xtrm <[email protected]> Date: Sat May 11 00:13:42 2024 +0200 🔨 chore(loader): remove debug duplicate code commit 0ab7a64 Author: xtrm <[email protected]> Date: Fri May 10 23:32:22 2024 +0200 🐛 fix(MixinSandbox): whoops, forgot about the easy way commit 99470af Author: xtrm <[email protected]> Date: Fri May 10 23:30:20 2024 +0200 🐛 fix(loader): optimize tryRetransform commit 67709d0 Author: xtrm <[email protected]> Date: Fri May 10 23:28:25 2024 +0200 🔨 chore(loader): cleanup WeaveLogAppender commit 4553e2c Author: xtrm <[email protected]> Date: Tue May 7 15:50:48 2024 +0200 🔨 chore(loader): remove commented-out code commit 449ccff Author: xtrm <[email protected]> Date: Tue May 7 15:49:28 2024 +0200 ✨ feature(loader/bootstrap): add a way to make hooked ClassLoaders ignore packages commit 018f1e6 Author: xtrm <[email protected]> Date: Tue May 7 15:17:11 2024 +0200 🚧 wip(loader/bootstrap): try and fix logger double-initialization commit 1cf4f93 Author: xtrm <[email protected]> Date: Tue May 7 06:05:51 2024 +0200 ✨ feature(loader): add java property to dump transformed bytecode commit 7769f62 Author: xtrm <[email protected]> Date: Tue May 7 04:16:04 2024 +0200 🔨 chore(loader): update println statement commit 861439e Author: xtrm <[email protected]> Date: Sun May 5 03:29:30 2024 +0200 🔨 chore(loader): println -> klog.warn commit aac0923 Author: xtrm <[email protected]> Date: Sat May 4 00:50:06 2024 +0200 🔨 chore(loader/Utilities.kt): change exit to return `Nothing` commit 952be40 Author: xtrm <[email protected]> Date: Sat May 4 00:31:55 2024 +0200 ✨ feature(loader): add nice console + file logging Co-authored-by: xtrm <[email protected]> Co-authored-by: 770grappenmaker <[email protected]> Closes #46
Weave-MC · Jul 7, 2024 · ae9ade1 · ae9ade1
1 parent 3cf8e6a
commit ae9ade1
Show file tree

Hide file tree

Showing 15 changed files with 377 additions and 235 deletions.
diff --git a/gradle/libs.versions.toml b/gradle/libs.versions.toml
@@ -6,12 +6,14 @@ kxSer = "1.5.1"
 mappingsUtil = "0.1.6"
 weaveInternals = "1.0.0-b.3"
 gradle-shadow = "8.1.1"
+klog = "0.0.5"
 
 [libraries]
 asm = { module = "org.ow2.asm:asm", version.ref = "asm" }
 asm-tree = { module = "org.ow2.asm:asm-tree", version.ref = "asm" }
 asm-commons = { module = "org.ow2.asm:asm-commons", version.ref = "asm" }
 asm-util = { module = "org.ow2.asm:asm-util", version.ref = "asm" }
+klog = { module = "me.xtrm:klog", version.ref = "klog" }
 mixin = { module = "net.fabricmc:sponge-mixin", version.ref = "mixin" }
 kxSer = { module = "org.jetbrains.kotlinx:kotlinx-serialization-json", version.ref = "kxSer" }
 mappingsUtil = { module = "io.github.770grappenmaker:mappings-util", version.ref = "mappingsUtil" }

diff --git a/loader/build.gradle.kts b/loader/build.gradle.kts
@@ -1,3 +1,5 @@
+@file:Suppress("VulnerableLibrariesLocal")
+
 plugins {
     id("config-kotlin")
     id("config-shade")
@@ -10,6 +12,7 @@ repositories {
 
 dependencies {
     shade(project(":api"))
+    shade(libs.klog)
     shade(libs.kxSer)
     shade(libs.bundles.asm)
     shade(libs.weaveInternals)

diff --git a/loader/src/main/kotlin/net/weavemc/loader/InjectionHandler.kt b/loader/src/main/kotlin/net/weavemc/loader/InjectionHandler.kt
@@ -1,10 +1,12 @@
 package net.weavemc.loader
 
 import com.grappenmaker.mappings.LambdaAwareRemapper
+import me.xtrm.klog.dsl.klog
 import com.grappenmaker.mappings.remap
 import net.weavemc.api.Hook
 import net.weavemc.internals.dump
 import net.weavemc.loader.bootstrap.transformer.SafeTransformer
+import net.weavemc.loader.util.MappingsHandler.remap
 import net.weavemc.loader.util.*
 import org.objectweb.asm.ClassReader
 import org.objectweb.asm.ClassWriter
@@ -80,7 +82,7 @@ object InjectionHandler : SafeTransformer {
 
                 runCatching {
                     classWriter.toByteArray().dump(bytecodeOut.absolutePath)
-                }.onFailure { println("Failed to dump bytecode for $bytecodeOut") }
+                }.onFailure { klog.error("Failed to dump bytecode for $bytecodeOut", it) }
             }
 
             return classWriter.toByteArray()

diff --git a/loader/src/main/kotlin/net/weavemc/loader/WeaveLoader.kt b/loader/src/main/kotlin/net/weavemc/loader/WeaveLoader.kt
@@ -1,6 +1,7 @@
 package net.weavemc.loader
 
 import com.grappenmaker.mappings.*
+import me.xtrm.klog.Logger
 import net.weavemc.api.Hook
 import net.weavemc.api.ModInitializer
 import net.weavemc.internals.GameInfo
@@ -21,6 +22,8 @@ class WeaveLoader(
     private val instrumentation: Instrumentation,
     private val mappedModJars: List<File>
 ) {
+    private val logger = Logger(WeaveLoader::class.java.name)
+
     /**
      * Stored list of [WeaveMod]s.
      *
@@ -50,12 +53,12 @@ class WeaveLoader(
         private var INSTANCE: WeaveLoader? = null
 
         @JvmStatic
-        fun getInstance() =
-            INSTANCE ?: fatalError("Attempted to retrieve WeaveLoader instance before it has been instantiated!")
+        fun getInstance() = INSTANCE
+            ?: fatalError("Attempted to retrieve WeaveLoader instance before it has been instantiated!")
     }
 
     init {
-        println("[Weave] Initializing Weave")
+        logger.info("Initializing Weave")
 
         INSTANCE = this
         launchStart = System.currentTimeMillis()
@@ -65,59 +68,57 @@ class WeaveLoader(
     }
 
     private fun finalize() {
-        println("[Weave] Finalizing Weave")
+        logger.trace("Finalizing Weave loading...")
         mappedModJars.forEach { it.registerAsMod() }
-        println("[Weave] Verifying dependencies")
+        logger.trace("Verifying dependencies")
         verifyDependencies()
-        println("[Weave] Populating mixin modifiers")
+        logger.trace("Populating mixin modifiers")
         populateMixinModifiers()
-        println("[Weave] Setting up access wideners")
+        logger.trace("Setting up access wideners")
         setupAccessWideners()
 
-        println("[Weave] calling preInit() for mods")
+        logger.trace("Calling preInit() for mods")
         // TODO remove
         // Invoke preInit() once everything is done.
         mods.forEach { weaveMod ->
             weaveMod.config.entryPoints.forEach { entrypoint ->
                 runCatching {
+                    logger.debug("Calling $entrypoint#preInit")
                     instantiate<ModInitializer>(entrypoint)
                 }.onFailure {
-                    it.printStackTrace()
-                    println("Failed to instantiate $entrypoint#preInit")
+                    logger.error("Failed to instantiate $entrypoint#preInit", it)
                 }.onSuccess {
                     runCatching {
                         @Suppress("DEPRECATION")
                         it.preInit(instrumentation)
                     }.onFailure {
-                        it.printStackTrace()
-                        println("Exception thrown when invoking $entrypoint#preInit")
+                        logger.error("Exception thrown when invoking $entrypoint#preInit", it)
                     }
                 }
             }
         }
 
-        println("[Weave] Initialized Weave")
+        logger.info("Weave initialized in ${System.currentTimeMillis() - launchStart}ms")
         updateLaunchTimes()
     }
 
     /**
      * Invokes Weave Mods' init. @see net.weavemc.api.ModInitializer
      * Invoked at the head of Minecraft's main method. @see net.weavemc.loader.transformer.ModInitializerHook
      */
+    @Suppress("unused")
     fun initializeMods() {
         mods.forEach { weaveMod ->
             weaveMod.config.entryPoints.forEach { entrypoint ->
                 runCatching {
                     instantiate<ModInitializer>(entrypoint)
                 }.onFailure {
-                    it.printStackTrace()
-                    println("Failed to instantiate $entrypoint#init")
+                    logger.error("Failed to instantiate $entrypoint#init", it)
                 }.onSuccess {
                     runCatching {
                         it.init()
                     }.onFailure {
-                        it.printStackTrace()
-                        println("Exception thrown when invoking $entrypoint#init")
+                        logger.error("Exception thrown when invoking $entrypoint#init", it)
                     }
                 }
             }
@@ -149,7 +150,8 @@ class WeaveLoader(
     }
 
     private fun mixinForNamespace(namespace: String) = mixinInstances.getOrPut(namespace) {
-        val parent = classLoader.backing
+        logger.debug("Creating a new SandboxedMixinLoader for namespace $namespace")
+        val parent = classLoader.weaveBacking
         SandboxedMixinLoader(
             parent = parent,
             loader = ClasspathLoaders.fromLoader(parent)
@@ -198,7 +200,7 @@ class WeaveLoader(
      * Registers mod's hooks and mixins then adds to mods list for later instantiation
      */
     private fun File.registerAsMod() {
-        println("[Weave] Registering ${this.name}")
+        logger.trace("Registering mod $name")
         classLoader.addWeaveURL(this.toURI().toURL())
 
         JarFile(this).use { jar ->
@@ -209,15 +211,15 @@ class WeaveLoader(
             instrumentation.appendToSystemClassLoaderSearch(jar)
 
             config.hooks.forEach { hook ->
-                println("[Weave] Registering hook $hook")
+                logger.trace("Registering hook $hook")
                 InjectionHandler.registerModifier(ModHook(config.namespace, instantiate(hook)))
             }
 
             val state = mixinForNamespace(config.namespace).state
             config.mixinConfigs.forEach { state.registerMixin(modId, it) }
 
             mods += WeaveMod(modId, config)
-            println("[Weave] Registered ${this.name}")
+            logger.trace("Registered mod $name")
         }
     }
 }
diff --git a/loader/src/main/kotlin/net/weavemc/loader/bootstrap/Agent.kt b/loader/src/main/kotlin/net/weavemc/loader/bootstrap/Agent.kt
@@ -1,5 +1,8 @@
 package net.weavemc.loader.bootstrap
 
+import me.xtrm.klog.Level
+import me.xtrm.klog.dsl.klog
+import me.xtrm.klog.dsl.klogConfig
 import net.weavemc.api.Tweaker
 import net.weavemc.internals.GameInfo
 import net.weavemc.internals.MinecraftVersion
@@ -16,13 +19,20 @@ import java.net.URL
 import java.net.URLClassLoader
 import java.util.jar.JarFile
 
+private val logger by klog
+
 /**
  * The JavaAgent's `premain()` method, this is where initialization of Weave Loader begins.
  * Weave Loader's initialization begins by instantiating [WeaveLoader]
  */
 @Suppress("UNUSED_PARAMETER")
 fun premain(opt: String?, inst: Instrumentation) {
-    println("[Weave] Attached Weave")
+    klogConfig {
+        defaultLevel = Level.INFO
+        appenders = mutableListOf(WeaveLogAppender)
+    }
+
+    logger.info("Attached Weave")
 
     setGameInfo()
 
@@ -50,7 +60,7 @@ fun premain(opt: String?, inst: Instrumentation) {
 class TweakerClassLoader(urls: List<URL>) : URLClassLoader(urls.toTypedArray(), ClassLoader.getSystemClassLoader())
 
 private fun callTweakers(inst: Instrumentation, mods: List<File>) {
-    println("[Weave] Calling tweakers")
+    logger.info("Calling tweakers")
 
     val tweakers = mods
         .mapNotNull { runCatching { JarFile(it).use { it.fetchModConfig(JSON) } }.getOrNull() }
@@ -60,7 +70,7 @@ private fun callTweakers(inst: Instrumentation, mods: List<File>) {
     val loader = TweakerClassLoader(mods.map { it.toURI().toURL() })
 
     for (tweaker in tweakers) {
-        println("[Weave] Calling tweaker: $tweaker")
+        logger.trace("Calling tweaker: $tweaker")
         instantiate<Tweaker>(tweaker, loader).tweak(inst)
     }
 }

diff --git a/loader/src/main/kotlin/net/weavemc/loader/bootstrap/Bootstrap.kt b/loader/src/main/kotlin/net/weavemc/loader/bootstrap/Bootstrap.kt
@@ -1,5 +1,6 @@
 package net.weavemc.loader.bootstrap
 
+import me.xtrm.klog.dsl.klog
 import net.weavemc.internals.GameInfo
 import net.weavemc.loader.bootstrap.transformer.ApplicationWrapper
 import net.weavemc.loader.bootstrap.transformer.SafeTransformer
@@ -10,55 +11,51 @@ import java.io.File
 import java.lang.instrument.Instrumentation
 
 object Bootstrap {
-    fun bootstrap(inst: Instrumentation, mods: List<File>) {
-        inst.addTransformer(object: SafeTransformer {
-            override fun transform(loader: ClassLoader?, className: String, originalClass: ByteArray): ByteArray? {
-                if (className == "net/minecraft/client/main/Main") {
-                    if (loader == ClassLoader.getSystemClassLoader())
-                        return ApplicationWrapper.insertWrapper(className, originalClass)
+    val logger by klog
 
-                    printBootstrap(loader)
+    fun bootstrap(inst: Instrumentation, mods: List<File>) = inst.addTransformer(object: SafeTransformer {
+        override fun transform(loader: ClassLoader?, className: String, originalClass: ByteArray): ByteArray? {
+            if (className != "net/minecraft/client/main/Main") return null
+            if (loader == ClassLoader.getSystemClassLoader())
+                return ApplicationWrapper.insertWrapper(className, originalClass)
 
-                    // remove bootstrap transformers
-                    inst.removeTransformer(this)
-                    inst.removeTransformer(URLClassLoaderTransformer)
+            printBootstrap(loader)
 
-                    val clAccessor = if (loader is URLClassLoaderAccessor) loader
-                    else fatalError("Failed to transform URLClassLoader to implement URLClassLoaderAccessor. Impossible to recover")
+            // remove bootstrap transformers
+            inst.removeTransformer(this)
+            inst.removeTransformer(URLClassLoaderTransformer)
 
-                    runCatching {
-                        clAccessor.addWeaveURL(javaClass.protectionDomain.codeSource.location)
-                    }.onFailure {
-                        it.printStackTrace()
-                        fatalError("Failed to deliberately add Weave to the target classloader")
-                    }
+            val clAccessor = if (loader is URLClassLoaderAccessor) loader
+            else fatalError("Failed to transform URLClassLoader to implement URLClassLoaderAccessor. Impossible to recover")
 
-                    println("[Weave] Bootstrapping complete.")
-
-                    /**
-                     * Start the Weave Loader initialization phase
-                     */
-                    val wlc = loader.loadClass("net.weavemc.loader.WeaveLoader")
-                    wlc.getConstructor(
-                        URLClassLoaderAccessor::class.java,
-                        Instrumentation::class.java,
-                        java.util.List::class.java
-                    ).newInstance(clAccessor, inst, mods)
-                }
+            runCatching {
+                clAccessor.addWeaveURL(javaClass.protectionDomain.codeSource.location)
+            }.onFailure {
+                it.printStackTrace()
+                fatalError("Failed to deliberately add Weave to the target classloader")
+            }
 
-                return null
+            logger.info("Bootstrapping complete, initializing loader...")
+
+            runCatching {
+                loader.loadClass("net.weavemc.loader.WeaveLoader").getConstructor(
+                    URLClassLoaderAccessor::class.java,
+                    Instrumentation::class.java,
+                    java.util.List::class.java
+                ).newInstance(clAccessor, inst, mods)
+            }.onFailure {
+                logger.fatal("Failed to instantiate WeaveLoader", it)
+                exit(-1)
             }
-        })
-    }
+
+            return null
+        }
+    })
 
     private fun printBootstrap(loader: ClassLoader?) {
-        println(
-            """
-            [Weave] Bootstrapping...
-                - Version: ${GameInfo.version.versionName}
-                - Client: ${GameInfo.client.clientName}
-                - Loader: $loader
-            """.trimIndent()
-        )
+        logger.info("Bootstrapping Weave Loader...")
+        logger.debug(" - Version: ${GameInfo.version.versionName}")
+        logger.debug(" - Client: ${GameInfo.client.clientName}")
+        logger.debug(" - Loader: $loader")
     }
 }