Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

LaunchWrapper outputs a mile of error messages when legacy.debugClassLoading is enabled for WindowsAnsiOutputStream #22

Open
Pokechu22 opened this issue Feb 2, 2018 · 6 comments
Open

LaunchWrapper outputs a mile of error messages when legacy.debugClassLoading is enabled for WindowsAnsiOutputStream #22

Pokechu22 opened this issue Feb 2, 2018 · 6 comments

Comments

@Pokechu22
Copy link

(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.
@thiakil
Copy link

thiakil commented May 10, 2018

Assuming by your mention of the PR that you're using a custom compiled version, have you tried adding org.fusesource.jansi to addClassLoaderExclusion in the LaunchClassLoader constructor?

@Pokechu22
Copy link
Author

That does seem to solve it (I added addClassLoaderExclusion("org.fusesource.jansi."); to it).

thiakil added a commit to thiakil/LegacyLauncher that referenced this issue May 10, 2018
@thiakil
Add org.fusesource.jansi package to classloader exclusions, fixes Moj…
0fa9615 
…ang#22
@Hallowizer
Copy link

Can you send the full mile? I thought I found something useful but it was cut off by your “skipping several hundred lines”.

@Pokechu22
Copy link
Author

It should be in the outlong.zip I linked before the bit, but I'm not 100% sure (it's been a while).

@Hallowizer
Copy link

I found the problem, I will fix it soon.

@thiakil
Copy link

thiakil commented Oct 15, 2018

What problem? the "mile long" log is caused by it trying to classload a Log4J related class through the LaunchClassLoader while its trying to use it itself, which just won't work. The fix for it is commented in this thread & linked via a commit on a branch

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@thiakil @Pokechu22 @Hallowizer