Quick and dirty mixin to time and log event timings to a "csv" (uses semicolon) (#411)

* Quick and dirty mixin to time and log event timings to a "csv" (uses semicolon)

* Add a PreInitMixinPlugin
Gate log mod times behind a property
Used a Buffered Writer

* redundant remaps

Author: mitchej123

build.gradle.kts

@@ -10,6 +10,9 @@ tasks.jar {
         attributes("CCTransformer" to "com.mitchej123.hodgepodge.asm.transformers.early.EarlyClassTransformer")
     }
 }
+minecraft {
+    extraRunJvmArguments.add("-Dhodgepodge.logModTimes=true")
+}
 
 tasks.processResources {
     inputs.property("version", project.version.toString())

src/main/java/com/mitchej123/hodgepodge/mixins/hooks/ModProfileResult.java

@@ -0,0 +1,20 @@
+package com.mitchej123.hodgepodge.mixins.hooks;
+
+import cpw.mods.fml.common.ModContainer;
+
+public class ModProfileResult implements Comparable<ModProfileResult> {
+
+    public final long time;
+    public final ModContainer mod;
+
+    public ModProfileResult(long time, ModContainer mod) {
+        this.time = time;
+        this.mod = mod;
+    }
+
+    @Override
+    public int compareTo(ModProfileResult o) {
+        return Long.compare(o.time, time);
+    }
+
+}

src/main/java/com/mitchej123/hodgepodge/mixins/plugin/HodgepodgePreInitMixinPlugin.java

@@ -0,0 +1,51 @@
+package com.mitchej123.hodgepodge.mixins.plugin;
+
+import java.util.ArrayList;
+import java.util.List;
+import java.util.Set;
+
+import org.spongepowered.asm.lib.tree.ClassNode;
+import org.spongepowered.asm.mixin.extensibility.IMixinConfigPlugin;
+import org.spongepowered.asm.mixin.extensibility.IMixinInfo;
+
+public class HodgepodgePreInitMixinPlugin implements IMixinConfigPlugin {
+
+    @Override
+    public void onLoad(String mixinPackage) {
+
+    }
+
+    @Override
+    public String getRefMapperConfig() {
+        return null;
+    }
+
+    @Override
+    public boolean shouldApplyMixin(String targetClassName, String mixinClassName) {
+        return true;
+    }
+
+    @Override
+    public void acceptTargets(Set<String> myTargets, Set<String> otherTargets) {
+
+    }
+
+    @Override
+    public List<String> getMixins() {
+        List<String> mixins = new ArrayList<>();
+        if (Boolean.getBoolean("hodgepodge.logModTimes")) {
+            mixins.add("MixinLoadController_logModTimes");
+        }
+        return mixins;
+    }
+
+    @Override
+    public void preApply(String s, ClassNode classNode, String s1, IMixinInfo iMixinInfo) {
+
+    }
+
+    @Override
+    public void postApply(String s, ClassNode classNode, String s1, IMixinInfo iMixinInfo) {
+
+    }
+}

src/main/java/com/mitchej123/hodgepodge/mixins/preinit/MixinLoadController_logModTimes.java

@@ -0,0 +1,73 @@
+package com.mitchej123.hodgepodge.mixins.preinit;
+
+import java.io.BufferedWriter;
+import java.io.FileWriter;
+import java.io.IOException;
+import java.io.PrintWriter;
+import java.util.ArrayList;
+import java.util.Map;
+
+import org.spongepowered.asm.mixin.Mixin;
+import org.spongepowered.asm.mixin.injection.At;
+import org.spongepowered.asm.mixin.injection.Inject;
+import org.spongepowered.asm.mixin.injection.callback.CallbackInfo;
+
+import com.llamalad7.mixinextras.injector.wrapoperation.Operation;
+import com.llamalad7.mixinextras.injector.wrapoperation.WrapOperation;
+import com.mitchej123.hodgepodge.Common;
+import com.mitchej123.hodgepodge.mixins.hooks.ModProfileResult;
+
+import cpw.mods.fml.common.LoadController;
+import cpw.mods.fml.common.LoaderState;
+import cpw.mods.fml.common.ModContainer;
+import cpw.mods.fml.common.event.FMLEvent;
+import it.unimi.dsi.fastutil.objects.Object2ObjectOpenHashMap;
+
+@Mixin(value = LoadController.class, remap = false)
+public class MixinLoadController_logModTimes {
+
+    private static Map<String, ArrayList<ModProfileResult>> results = new Object2ObjectOpenHashMap<>();
+
+    @WrapOperation(
+            method = "propogateStateMessage",
+            at = @At(
+                    value = "INVOKE",
+                    target = "Lcpw/mods/fml/common/LoadController;sendEventToModContainer(Lcpw/mods/fml/common/event/FMLEvent;Lcpw/mods/fml/common/ModContainer;)V"))
+    private void timeModEvent(LoadController instance, FMLEvent event, ModContainer modContainer,
+            Operation<Void> original) {
+
+        final long start = System.nanoTime();
+
+        original.call(instance, event, modContainer);
+        if (results == null) return;
+
+        final long timeTaken = System.nanoTime() - start;
+        results.computeIfAbsent(event.getEventType(), k -> new ArrayList<>())
+                .add(new ModProfileResult(timeTaken, modContainer));
+    }
+
+    @Inject(
+            method = "Lcpw/mods/fml/common/LoadController;distributeStateMessage(Lcpw/mods/fml/common/LoaderState;[Ljava/lang/Object;)V",
+            at = @At(value = "TAIL"))
+    public void printResults(LoaderState state, Object[] eventData, CallbackInfo ci) {
+        if (results == null || state != LoaderState.AVAILABLE) return;
+        try {
+            PrintWriter writer = new PrintWriter(new BufferedWriter(new FileWriter("modtimes.csv", false)));
+
+            writer.println("event;modid;modname;time");
+            results.forEach((type, results) -> {
+                results.sort(null);
+                results.forEach(result -> {
+                    final String modid = result.mod.getModId();
+                    writer.println(type + ";" + modid + ";" + result.mod.getName() + ";" + result.time / 1000000);
+                });
+
+            });
+            writer.close();
+        } catch (IOException e) {
+            Common.log.error("Failed to write modtimes.csv", e);
+        }
+        results = null;
+    }
+
+}

src/main/resources/mixins.hodgepodge.json

@@ -2,7 +2,9 @@
   "required": true,
   "minVersion": "0.8.3-GTNH",
   "refmap": "mixins.hodgepodge.refmap.json",
-  "target": "@env(DEFAULT)",
-  "compatibilityLevel": "JAVA_8"
+  "target": "@env(PREINIT)",
+  "compatibilityLevel": "JAVA_8",
+  "plugin": "com.mitchej123.hodgepodge.mixins.plugin.HodgepodgePreInitMixinPlugin",
+  "package": "com.mitchej123.hodgepodge.mixins.preinit"
 }