Big cleanup of logging. Might do some tweaks of the userdev logging, but this should be good for vanilla..

Signed-off-by: cpw <cpw+github@weeksfamily.ca>

src/main/java/net/minecraftforge/event/RegistryEvent.java

@@ -45,6 +45,10 @@ public class RegistryEvent<T extends IForgeRegistryEntry<T>> extends GenericEven
      */
     public static class NewRegistry extends net.minecraftforge.eventbus.api.Event
     {
+        @Override
+        public String toString() {
+            return "RegistryEvent.NewRegistry";
+        }
     }
 
     /**
@@ -80,6 +84,10 @@ public class RegistryEvent<T extends IForgeRegistryEntry<T>> extends GenericEven
             return name;
         }
 
+        @Override
+        public String toString() {
+            return "RegistryEvent.Register<"+getName()+">";
+        }
     }
 
     public static class MissingMappings<T extends IForgeRegistryEntry<T>> extends RegistryEvent<T>

src/main/java/net/minecraftforge/fml/AutomaticEventSubscriber.java

@@ -66,7 +66,7 @@ public class AutomaticEventSubscriber
             if (Objects.equals(mod.getModId(), modId) && sides.contains(FMLEnvironment.dist)) {
                 try
                 {
-                    LOGGER.info(LOADING, "Auto-subscribing {} to {}", ad.getClassType().getClassName(), busTarget);
+                    LOGGER.debug(LOADING, "Auto-subscribing {} to {}", ad.getClassType().getClassName(), busTarget);
                     busTarget.bus().get().register(Class.forName(ad.getClassType().getClassName(), true, loader));
                 }
                 catch (ClassNotFoundException e)

src/main/java/net/minecraftforge/fml/LaunchTesting.java

@@ -37,15 +37,15 @@ public class LaunchTesting
     public static void main(String... args) throws InterruptedException
     {
         Configurator.setRootLevel(Level.DEBUG);
-        final MarkerFilter classloadingFilter = MarkerFilter.createFilter("CLASSLOADING", Filter.Result.DENY, Filter.Result.NEUTRAL);
+//        final MarkerFilter classloadingFilter = MarkerFilter.createFilter("CLASSLOADING", Filter.Result.DENY, Filter.Result.NEUTRAL);
-        final MarkerFilter launchpluginFilter = MarkerFilter.createFilter("LAUNCHPLUGIN", Filter.Result.DENY, Filter.Result.NEUTRAL);
+//        final MarkerFilter launchpluginFilter = MarkerFilter.createFilter("LAUNCHPLUGIN", Filter.Result.DENY, Filter.Result.NEUTRAL);
         final MarkerFilter axformFilter= MarkerFilter.createFilter("AXFORM", Filter.Result.DENY, Filter.Result.NEUTRAL);
         final MarkerFilter eventbusFilter = MarkerFilter.createFilter("EVENTBUS", Filter.Result.DENY, Filter.Result.NEUTRAL);
         final MarkerFilter distxformFilter = MarkerFilter.createFilter("DISTXFORM", Filter.Result.DENY, Filter.Result.NEUTRAL);
 //        final MarkerFilter scannerFilter = MarkerFilter.createFilter("SCAN", Filter.Result.DENY, Filter.Result.NEUTRAL);
         final LoggerContext logcontext = LoggerContext.getContext(false);
-        logcontext.getConfiguration().addFilter(classloadingFilter);
+//        logcontext.getConfiguration().addFilter(classloadingFilter);
-        logcontext.getConfiguration().addFilter(launchpluginFilter);
+//        logcontext.getConfiguration().addFilter(launchpluginFilter);
 //        logcontext.getConfiguration().addFilter(axformFilter);
 //        logcontext.getConfiguration().addFilter(eventbusFilter);
 //        logcontext.getConfiguration().addFilter(distxformFilter);

src/main/java/net/minecraftforge/fml/ModList.java

@@ -94,13 +94,13 @@ public class ModList
     }
 
     private void dispatchSynchronousEvent(LifecycleEventProvider.LifecycleEvent lifecycleEvent, final Consumer<List<ModLoadingException>> errorHandler) {
-        LOGGER.info(LOADING, "Dispatching synchronous event {}", lifecycleEvent);
+        LOGGER.debug(LOADING, "Dispatching synchronous event {}", lifecycleEvent);
         FMLLoader.getLanguageLoadingProvider().forEach(lp->lp.consumeLifecycleEvent(()->lifecycleEvent));
         this.mods.forEach(m->m.transitionState(lifecycleEvent, errorHandler));
         FMLLoader.getLanguageLoadingProvider().forEach(lp->lp.consumeLifecycleEvent(()->lifecycleEvent));
     }
     private void dispatchParallelEvent(LifecycleEventProvider.LifecycleEvent lifecycleEvent, final Consumer<List<ModLoadingException>> errorHandler) {
-        LOGGER.info(LOADING, "Dispatching parallel event {}", lifecycleEvent);
+        LOGGER.debug(LOADING, "Dispatching parallel event {}", lifecycleEvent);
         FMLLoader.getLanguageLoadingProvider().forEach(lp->lp.consumeLifecycleEvent(()->lifecycleEvent));
         DeferredWorkQueue.clear();
         try

src/main/java/net/minecraftforge/fml/event/lifecycle/ModLifecycleEvent.java

@@ -23,6 +23,7 @@ import net.minecraftforge.eventbus.api.Event;
 import net.minecraftforge.fml.InterModComms;
 import net.minecraftforge.fml.ModContainer;
 
+import java.util.Arrays;
 import java.util.function.Predicate;
 import java.util.stream.Stream;
 
@@ -42,7 +43,7 @@ public class ModLifecycleEvent extends Event
     public final String description()
     {
        String cn = getClass().getName();
-       return cn.substring(cn.lastIndexOf('.')+4,cn.length()-5);
+       return cn.substring(cn.lastIndexOf('.')+1);
     }
 
     public Stream<InterModComms.IMCMessage> getIMCStream() {
@@ -52,4 +53,9 @@ public class ModLifecycleEvent extends Event
     public Stream<InterModComms.IMCMessage> getIMCStream(Predicate<String> methodFilter) {
         return InterModComms.getMessages(this.container.getModId(), methodFilter);
     }
+
+    @Override
+    public String toString() {
+        return description();
+    }
 }

src/main/java/net/minecraftforge/fml/javafmlmod/FMLModContainer.java

@@ -98,11 +98,11 @@ public class FMLModContainer extends ModContainer
 
     private void fireEvent(LifecycleEventProvider.LifecycleEvent lifecycleEvent) {
         final Event event = lifecycleEvent.getOrBuildEvent(this);
-        LOGGER.info(LOADING, "Firing event for modid {} : {}", this.getModId(), event.getClass().getName());
+        LOGGER.debug(LOADING, "Firing event for modid {} : {}", this.getModId(), event);
         try
         {
             eventBus.post(event);
-            LOGGER.debug(LOADING, "Fired event for modid {} : {}", this.getModId(), event.getClass().getName());
+            LOGGER.debug(LOADING, "Fired event for modid {} : {}", this.getModId(), event);
         }
         catch (Throwable e)
         {

src/main/java/net/minecraftforge/registries/GameData.java

@@ -65,6 +65,8 @@ import java.util.function.Consumer;
 import java.util.function.Predicate;
 import java.util.stream.Collectors;
 
+import static net.minecraftforge.fml.Logging.CORE;
+
 /**
  * INTERNAL ONLY
  * MODDERS SHOULD HAVE NO REASON TO USE THIS CLASS
@@ -809,9 +811,9 @@ public class GameData
             if (i==keysSize-1) lifecycleEventProvider.changeProgression(LifecycleEventProvider.LifecycleEvent.Progression.NEXT);
             eventDispatcher.accept(lifecycleEventProvider);
             reg.freeze();
-            LOGGER.info("{} Applying holder lookups", rl.toString());
+            LOGGER.debug(CORE,"Applying holder lookups: {}", rl.toString());
             ObjectHolderRegistry.applyObjectHolders(rl::equals);
-            LOGGER.info("{} Holder lookups applied", rl.toString());
+            LOGGER.debug(CORE,"Holder lookups applied: {}", rl.toString());
         }
     }
 

src/main/java/net/minecraftforge/registries/ObjectHolderRegistry.java

@@ -45,6 +45,8 @@ import org.apache.logging.log4j.Logger;
 import org.objectweb.asm.Opcodes;
 import org.objectweb.asm.Type;
 
+import static net.minecraftforge.fml.Logging.CORE;
+
 /**
  * Internal registry for tracking {@link ObjectHolder} references
  */
@@ -87,7 +89,7 @@ public class ObjectHolderRegistry
 
     public static void findObjectHolders()
     {
-        LOGGER.info("Processing ObjectHolder annotations");
+        LOGGER.debug(CORE,"Processing ObjectHolder annotations");
         final List<ModFileScanData.AnnotationData> annotations = ModList.get().getAllScanData().stream()
             .map(ModFileScanData::getAnnotations)
             .flatMap(Collection::stream)

src/main/resources/log4j2.xml

@@ -3,31 +3,31 @@
     <Appenders>
         <Console name="SysOut" target="SYSTEM_OUT">
             <PatternLayout>
-                <LoggerNamePatternSelector defaultPattern="[%d{HH:mm:ss}] [%t/%level] [%logger]: %msg%n">
+                <LoggerNamePatternSelector defaultPattern="%highlight{[%d{HH:mm:ss.SSS}] [%t/%level] [%c{2.}/%markerSimpleName]: %msg%n}">
                     <!-- don't include the full logger name for Mojang's logs since they use full class names and it's very verbose -->
-                    <PatternMatch key="net.minecraft." pattern="[%d{HH:mm:ss}] [%t/%level] [minecraft/%logger{1}]: %msg%n"/>
+                    <PatternMatch key="net.minecraft." pattern="%highlight{[%d{HH:mm:ss.SSS}] [%t/%level] [minecraft/%logger{1}]: %msg%n}"/>
-                    <PatternMatch key="com.mojang." pattern="[%d{HH:mm:ss}] [%t/%level] [mojang/%logger{1}]: %msg%n"/>
+                    <PatternMatch key="com.mojang." pattern="%highlight{[%d{HH:mm:ss.SSS}] [%t/%level] [mojang/%logger{1}]: %msg%n}"/>
                 </LoggerNamePatternSelector>
             </PatternLayout>
         </Console>
         <Queue name="ServerGuiConsole" ignoreExceptions="true">
             <PatternLayout>
-                <LoggerNamePatternSelector defaultPattern="[%d{HH:mm:ss}] [%t/%level] [%logger]: %msg%n">
+                <LoggerNamePatternSelector defaultPattern="[%d{HH:mm:ss.SSS}] [%t/%level] [%c{2.}/%markerSimpleName]: %msg%n">
                     <!-- don't include the full logger name for Mojang's logs since they use full class names and it's very verbose -->
-                    <PatternMatch key="net.minecraft." pattern="[%d{HH:mm:ss}] [%t/%level] [minecraft/%logger{1}]: %msg%n"/>
+                    <PatternMatch key="net.minecraft." pattern="[%d{HH:mm:ss.SSS}] [%t/%level] [minecraft/%logger{1}]: %msg%n"/>
-                    <PatternMatch key="com.mojang." pattern="[%d{HH:mm:ss}] [%t/%level] [mojang/%logger{1}]: %msg%n"/>
+                    <PatternMatch key="com.mojang." pattern="[%d{HH:mm:ss.SSS}] [%t/%level] [mojang/%logger{1}]: %msg%n"/>
                 </LoggerNamePatternSelector>
             </PatternLayout>
         </Queue>
         <RollingRandomAccessFile name="File" fileName="logs/latest.log" filePattern="logs/%d{yyyy-MM-dd}-%i.log.gz">
-            <PatternLayout pattern="[%d{HH:mm:ss}] [%t/%level] [%logger]: %msg%n"/>
+            <PatternLayout pattern="[%d{ddMMMyyyy HH:mm:ss.SSS}] [%t/%level] [%logger/%markerSimpleName]: %msg%n"/>
             <Policies>
                 <TimeBasedTriggeringPolicy/>
                 <OnStartupTriggeringPolicy/>
             </Policies>
         </RollingRandomAccessFile>
         <RollingRandomAccessFile name="DebugFile" fileName="logs/debug.log" filePattern="logs/debug-%i.log.gz">
-            <PatternLayout pattern="[%d{HH:mm:ss}] [%t/%level] [%logger]: %msg%n"/>
+            <PatternLayout pattern="[%d{ddMMMyyyy HH:mm:ss.SSS}] [%t/%level] [%logger/%markerSimpleName]: %msg%n"/>
             <Policies>
                 <OnStartupTriggeringPolicy/>
                 <SizeBasedTriggeringPolicy size="200MB"/>
@@ -41,7 +41,13 @@
         <Logger level="${sys:forge.logging.mojang.level:-info}" name="net.minecraft"/>
         <Root level="all">
             <filters>
-                <MarkerFilter marker="NETWORK_PACKETS" onMatch="DENY" onMismatch="NEUTRAL"/>
+                <MarkerFilter marker="NETWORK_PACKETS" onMatch="${sys:forge.logging.marker.networking:-DENY}" onMismatch="NEUTRAL"/>
+                <MarkerFilter marker="CLASSLOADING" onMatch="${sys:forge.logging.marker.classloading:-DENY}" onMismatch="NEUTRAL"/>
+                <MarkerFilter marker="LAUNCHPLUGIN" onMatch="${sys:forge.logging.marker.launchplugin:-DENY}" onMismatch="NEUTRAL"/>
+                <MarkerFilter marker="AXFORM" onMatch="${sys:forge.logging.marker.accesstransformer:-DENY}" onMismatch="NEUTRAL"/>
+                <MarkerFilter marker="EVENTBUS" onMatch="${sys:forge.logging.marker.eventbus:-DENY}" onMismatch="NEUTRAL"/>
+                <MarkerFilter marker="DISTXFORM" onMatch="${sys:forge.logging.marker.dist:-DENY}" onMismatch="NEUTRAL"/>
+                <MarkerFilter marker="SCAN" onMatch="${sys:forge.logging.marker.scan:-DENY}" onMismatch="NEUTRAL"/>
             </filters>
             <AppenderRef ref="SysOut" level="${sys:forge.logging.console.level:-info}"/>
             <AppenderRef ref="ServerGuiConsole" level="${sys:forge.logging.console.level:-info}"/>