LaunchWrapper outputs a mile of error messages when legacy.debugClassLoading is enabled for WindowsAnsiOutputStream #22
Description
(n.b. the "mile" part isn't an exaggeration -- the output is 282602 lines long, and assuming 4 lines per inch, we have 5888 feet or 1.115 miles)
If legacy.debugClassLoading is enabled, a HUGE number of errors are output. This makes it very hard to use to actually find real errors. Here's my log:
outlong.zip
The class that is failing is org.fusesource.jansi.WindowsAnsiOutputStream, and when it fails, it generated a VERY long error:
17:44:12.235 [Test worker] ERROR LaunchWrapper - Exception encountered attempting classloading of org.fusesource.jansi.WindowsAnsiOutputStream
java.lang.StackOverflowError: null
at java.lang.ClassLoader.defineClass1(Native Method) ~[?:1.8.0_131]
at java.lang.ClassLoader.defineClass(ClassLoader.java:763) ~[?:1.8.0_131]
at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142) ~[?:1.8.0_131]
at java.net.URLClassLoader.defineClass(URLClassLoader.java:467) ~[?:1.8.0_131]
at java.net.URLClassLoader.access$100(URLClassLoader.java:73) ~[?:1.8.0_131]
at java.net.URLClassLoader$1.run(URLClassLoader.java:368) ~[?:1.8.0_131]
at java.net.URLClassLoader$1.run(URLClassLoader.java:362) ~[?:1.8.0_131]
at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_131]
at java.net.URLClassLoader.findClass(URLClassLoader.java:361) ~[?:1.8.0_131]
at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_131]
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:335) ~[?:1.8.0_131]
at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_131]
at java.lang.ClassLoader.defineClass1(Native Method) ~[?:1.8.0_131]
at java.lang.ClassLoader.defineClass(ClassLoader.java:763) ~[?:1.8.0_131]
at java.security.SecureClassLoader.defineClass(SecureClassLoader.java:142) ~[?:1.8.0_131]
at java.net.URLClassLoader.defineClass(URLClassLoader.java:467) ~[?:1.8.0_131]
at java.net.URLClassLoader.access$100(URLClassLoader.java:73) ~[?:1.8.0_131]
at java.net.URLClassLoader$1.run(URLClassLoader.java:368) ~[?:1.8.0_131]
at java.net.URLClassLoader$1.run(URLClassLoader.java:362) ~[?:1.8.0_131]
at java.security.AccessController.doPrivileged(Native Method) ~[?:1.8.0_131]
at java.net.URLClassLoader.findClass(URLClassLoader.java:361) ~[?:1.8.0_131]
at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_131]
at sun.misc.Launcher$AppClassLoader.loadClass(Launcher.java:335) ~[?:1.8.0_131]
at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_131]
at java.lang.Class.forName0(Native Method) ~[?:1.8.0_131]
at java.lang.Class.forName(Class.java:348) ~[?:1.8.0_131]
at sun.reflect.generics.factory.CoreReflectionFactory.makeNamedType(CoreReflectionFactory.java:114) ~[?:1.8.0_131]
at sun.reflect.generics.visitor.Reifier.visitClassTypeSignature(Reifier.java:125) ~[?:1.8.0_131]
at sun.reflect.generics.tree.ClassTypeSignature.accept(ClassTypeSignature.java:49) ~[?:1.8.0_131]
at sun.reflect.annotation.AnnotationParser.parseSig(AnnotationParser.java:439) ~[?:1.8.0_131]
at sun.reflect.annotation.AnnotationParser.parseClassValue(AnnotationParser.java:420) ~[?:1.8.0_131]
at sun.reflect.annotation.AnnotationParser.parseMemberValue(AnnotationParser.java:349) ~[?:1.8.0_131]
at sun.reflect.annotation.AnnotationParser.parseAnnotation2(AnnotationParser.java:286) ~[?:1.8.0_131]
at sun.reflect.annotation.AnnotationParser.parseAnnotations2(AnnotationParser.java:120) ~[?:1.8.0_131]
at sun.reflect.annotation.AnnotationParser.parseAnnotations(AnnotationParser.java:72) ~[?:1.8.0_131]
at java.lang.Class.createAnnotationData(Class.java:3521) ~[?:1.8.0_131]
at java.lang.Class.annotationData(Class.java:3510) ~[?:1.8.0_131]
at java.lang.Class.getAnnotation(Class.java:3415) ~[?:1.8.0_131]
at org.apache.logging.log4j.core.config.plugins.visitors.PluginVisitors.findVisitor(PluginVisitors.java:45) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.injectFields(PluginBuilder.java:171) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.plugins.util.PluginBuilder.build(PluginBuilder.java:121) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.AbstractConfiguration.createPluginObject(AbstractConfiguration.java:952) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:892) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:884) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.AbstractConfiguration.createConfiguration(AbstractConfiguration.java:884) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.AbstractConfiguration.doConfigure(AbstractConfiguration.java:508) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.AbstractConfiguration.initialize(AbstractConfiguration.java:232) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.AbstractConfiguration.start(AbstractConfiguration.java:244) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:545) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:617) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.LoggerContext.reconfigure(LoggerContext.java:634) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:229) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:242) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:45) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.LogManager.getContext(LogManager.java:174) ~[log4j-api-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:618) ~[log4j-api-2.8.1.jar:2.8.1]
at net.minecraft.launchwrapper.LogWrapper.configureLogging(LogWrapper.java:14) ~[launchwrapper-1.13-SNAPSHOT-with16.jar:?]
at net.minecraft.launchwrapper.LogWrapper.log(LogWrapper.java:28) ~[launchwrapper-1.13-SNAPSHOT-with16.jar:?]
at net.minecraft.launchwrapper.LogWrapper.finest(LogWrapper.java:66) ~[launchwrapper-1.13-SNAPSHOT-with16.jar:?]
at net.minecraft.launchwrapper.LaunchClassLoader.getClassBytes(LaunchClassLoader.java:360) ~[launchwrapper-1.13-SNAPSHOT-with16.jar:?]
at net.minecraft.launchwrapper.LaunchClassLoader.findClass(LaunchClassLoader.java:170) ~[launchwrapper-1.13-SNAPSHOT-with16.jar:?]
at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_131]
at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_131]
at org.apache.logging.log4j.util.LoaderUtil.loadClass(LoaderUtil.java:139) ~[log4j-api-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.appender.ConsoleAppender.getOutputStream(ConsoleAppender.java:261) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.appender.ConsoleAppender.getDefaultManager(ConsoleAppender.java:226) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.appender.ConsoleAppender.createDefaultAppenderForLayout(ConsoleAppender.java:172) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.AbstractConfiguration.setToDefault(AbstractConfiguration.java:581) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.DefaultConfiguration.<init>(DefaultConfiguration.java:47) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.LoggerContext.<init>(LoggerContext.java:86) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.createContext(ClassLoaderContextSelector.java:171) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.locateContext(ClassLoaderContextSelector.java:145) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.getContext(ClassLoaderContextSelector.java:74) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:227) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:45) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.LogManager.getContext(LogManager.java:174) ~[log4j-api-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:618) ~[log4j-api-2.8.1.jar:2.8.1]
at net.minecraft.launchwrapper.LogWrapper.configureLogging(LogWrapper.java:14) ~[launchwrapper-1.13-SNAPSHOT-with16.jar:?]
at net.minecraft.launchwrapper.LogWrapper.log(LogWrapper.java:28) ~[launchwrapper-1.13-SNAPSHOT-with16.jar:?]
at net.minecraft.launchwrapper.LogWrapper.finest(LogWrapper.java:66) ~[launchwrapper-1.13-SNAPSHOT-with16.jar:?]
at net.minecraft.launchwrapper.LaunchClassLoader.getClassBytes(LaunchClassLoader.java:360) ~[launchwrapper-1.13-SNAPSHOT-with16.jar:?]
at net.minecraft.launchwrapper.LaunchClassLoader.findClass(LaunchClassLoader.java:170) ~[launchwrapper-1.13-SNAPSHOT-with16.jar:?]
at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_131]
at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_131]
... skipping several hundred lines ...
at java.lang.ClassLoader.loadClass(ClassLoader.java:424) ~[?:1.8.0_131]
at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:1.8.0_131]
at org.apache.logging.log4j.util.LoaderUtil.loadClass(LoaderUtil.java:139) ~[log4j-api-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.appender.ConsoleAppender.getOutputStream(ConsoleAppender.java:261) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.appender.ConsoleAppender.getDefaultManager(ConsoleAppender.java:226) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.appender.ConsoleAppender.createDefaultAppenderForLayout(ConsoleAppender.java:172) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.AbstractConfiguration.setToDefault(AbstractConfiguration.java:581) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.config.DefaultConfiguration.<init>(DefaultConfiguration.java:47) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.LoggerContext.<init>(LoggerContext.java:86) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.createContext(ClassLoaderContextSelector.java:171) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.locateContext(ClassLoaderContextSelector.java:145) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.selector.ClassLoaderContextSelector.getContext(ClassLoaderContextSelector.java:74) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:227) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.core.impl.Log4jContextFactory.getContext(Log4jContextFactory.java:45) ~[log4j-core-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.LogManager.getContext(LogManager.java:174) ~[log4j-api-2.8.1.jar:2.8.1]
at org.apache.logging.log4j.LogManager.getLogger(LogManager.java:618) ~[log4j-api-2.8.1.jar:2.8.1]
at net.minecraft.launchwrapper.LogWrapper.configureLogging(LogWrapper.java:14) ~[launchwrapper-1.13-SNAPSHOT-with16.jar:?]
at net.minecraft.launchwrapper.LogWrapper.log(LogWrapper.java:28) ~[launchwrapper-1.13-SNAPSHOT-with16.jar:?]
The following ones are all NullPointerExceptions, but I'm not sure whether it's actually an NPE or just a stack overflow in disguise. They're for the same class, though.
Granted, these issues do not happen when the property is disabled. However, I still think 30 megabytes of error message is a bit excessive, even if the user normally cannot see it. Also, these errors probably negatively impact start times (although they aren't logged, they still happen).
These errors do go away if the system property log4j.skipJansi is set to true (mentioned on https://stackoverflow.com/a/29879464/3991344).
It's worth noting that these errors are not captured into the game output log — but that's to be expected, as it's while log4j is loading. In this case I captured it using my test case from here with systemProperty 'legacy.debugClassLoading', 'true' in the test block of the buildscript and ./gradlew test --info, but it can also happen in the actual launcher with -Dlegacy.debugClassLoading=true. As a second note, this is with the fix from #16; otherwise the actual class is obscured.