This is a regression introduced by the fix for MC-115797. It delays the server start about 2 or more seconds and makes adding custom Log4J plugins much harder.
Log4J is more or less modular: the core consists mostly out of independent plugins.
There are two ways it can find them at runtime:
By scanning the classpath. This is not really optimized so it just loads all classes in a certain package and checks if they are annotated with the plugin annotation.
For performance they have an annotation processor that writes the available plugins into a
Log4J2Plugins.dat
file.
In the old Log4J version before Minecraft 1.12 the annotation processor was not yet included, so only the log4j-core actually used the Log4J2Plugins.dat
file. In newer log4j versions the metadata file is also generated for custom plugins now, theoretically removing the need for any classpath scanning. However, the server JAR caused issues (see MC-115797) because the shaded server JAR now included Log4J2Plugins.dat
twice, once for log4j-core and once for authlib.
The solution for that is to merge them, and there are tools available to do this for Maven and Gradle. However, it was fixed by excluding both, even the one from log4j-core! Log4J handles that gracefully, however the consequence is that is forced to classload literally every single of its classes to check if they are plugins, not only a few classes from custom plugins.
You can easily see that if you enable Log4J's debug logging. It even shows several exceptions because it loads classes with missing dependencies (which are never used in Minecraft). See:
You can get this debug log by running:
java -Dorg.apache.logging.log4j.simplelog.StatusLogger.level=ALL -jar minecraft_server.1.12.jar
Loading all the classes takes about 2 or 3 seconds when starting the Vanilla server and can be observed by the delay until the first message is printed. It doesn't cause actual issues until a mod adds another Log4J plugin to the classpath: As soon as one Log4J2Plugins.dat
exist on the classpath, Log4J will no longer scan its classes, resulting in MC-115797 again.
The proper fix for this is to merge the Log4J2Plugins.dat
for log4j-core and authlib. There are tools available for Gradle and Maven to do this:
Gradle: https://github.com/TheBoegl/shadow-log4j-transformer
Maven: https://github.com/edwgiz/maven-shaded-log4j-transformer
Once this is done, classpath scanning can be disabled entirely by removing packages="com.mojang.util"
from the log4j2.xml
configuration. Log4J will detect them automatically.
I've also attached two profiler screenshots that show the difference with, and without Log4J2Plugins.dat
on the classpath. The server starts noticeably faster with it on the classpath.
Attachments
Comments 3
"Log4J2Plugins.dat was removed causing a slowdown of 3 secs on startup while it has to rescan all classes" is the issue, its just worded along with a fix(which is useful)
Erm... This is not a bug report, this is a suggestion. Please share feedback onĀ https://feedback.minecraft.net.