0

I've been playing around with Guice and stumbled upon this error that doesn't seem to make a lot of sense to me. It seems like whenever an error occurs during injection, Guice fails to properly log the injection error due to a failed message formatting. This could be a bug within Guice, I am not entirely sure.

The jar is being built using the maven-shade-plugin, which includes the necessary dependencies in the jar itself. Looking at the jar's contents, it definitely does contain the class that the NoClassDefFoundError is referring to. The injection itself works completely fine, as long as it does not run into any classes it cannot inject properly.

What makes this stranger is the fact that the code where the exception occurs is in the exact same file as the class that is missing. The following screenshot is taken using IntelliJ's built-in decompiler: Compiled Class

Contents of jar at com.google.inject.internal through winrar:

Jar contents

Stacktrace:

[23:32:10 WARN]: AsyncLogger error handling event seq=231, value='org.apache.logging.log4j.core.async.RingBufferLogEvent@64c2c9e5': java.lang.NoClassDefFoundError: java.lang.NoClassDefFoundError: com/google/inject/internal/Messages$FormatOptions
[23:32:10 WARN]:        at Dodgeball.jar//com.google.inject.internal.Messages.redBold(Messages.java:306)
[23:32:10 WARN]:        at Dodgeball.jar//com.google.inject.spi.ErrorDetail.lambda$format$0(ErrorDetail.java:61)
[23:32:10 WARN]:        at java.base/java.util.Optional.map(Optional.java:260)
[23:32:10 WARN]:        at Dodgeball.jar//com.google.inject.spi.ErrorDetail.format(ErrorDetail.java:61)
[23:32:10 WARN]:        at Dodgeball.jar//com.google.inject.internal.Messages.formatMessages(Messages.java:90)
[23:32:10 WARN]:        at Dodgeball.jar//com.google.inject.ProvisionException.getMessage(ProvisionException.java:60)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.impl.ThrowableProxy.<init>(ThrowableProxy.java:106)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.impl.ThrowableProxy.<init>(ThrowableProxy.java:94)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.async.RingBufferLogEvent.getThrownProxy(RingBufferLogEvent.java:326)
[23:32:10 WARN]:        at io.papermc.paper.logging.DelegateLogEvent.getThrownProxy(DelegateLogEvent.java:103)
[23:32:10 WARN]:        at io.papermc.paper.logging.ExtraClassInfoLogEvent.getThrownProxy(ExtraClassInfoLogEvent.java:21)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.pattern.ExtendedThrowablePatternConverter.format(ExtendedThrowablePatternConverter.java:63)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:38)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.layout.PatternLayout$PatternSelectorSerializer.toSerializable(PatternLayout.java:475)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.layout.PatternLayout.toText(PatternLayout.java:244)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:229)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:59)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:197)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:190)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:181)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender.append(RollingRandomAccessFileAppender.java:251)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.appender.rewrite.RewriteAppender.append(RewriteAppender.java:84)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.appender.rewrite.RewriteAppender.append(RewriteAppender.java:84)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:540)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:498)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:481)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:469)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:98)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.async.AsyncLogger.actualAsyncLog(AsyncLogger.java:488)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.async.RingBufferLogEvent.execute(RingBufferLogEvent.java:154)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.async.RingBufferLogEventHandler.onEvent(RingBufferLogEventHandler.java:46)
[23:32:10 WARN]:        at org.apache.logging.log4j.core.async.RingBufferLogEventHandler.onEvent(RingBufferLogEventHandler.java:29)
[23:32:10 WARN]:        at com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:168)
[23:32:10 WARN]:        at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:125)
[23:32:10 WARN]:        at java.base/java.lang.Thread.run(Thread.java:831)

Main Pom.xml (note that Valve is what contains guice):

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>com.mpolder</groupId>
    <artifactId>Dodgeball</artifactId>
    <version>1.0-SNAPSHOT</version>

    <properties>
        <maven.compiler.source>16</maven.compiler.source>
        <maven.compiler.target>16</maven.compiler.target>
    </properties>

    <build>
        <plugins>
            <plugin>
                <groupId>org.apache.maven.plugins</groupId>
                <artifactId>maven-shade-plugin</artifactId>
                <version>3.3.0-SNAPSHOT</version>
                <executions>
                    <execution>
                        <phase>package</phase>
                        <goals>
                            <goal>shade</goal>
                        </goals>
                        <configuration>
                            <finalName>Cameo-Dodgeball</finalName>
                            <relocations>
                                <relocation>
                                    <pattern>com.mpolder.valve</pattern>
                                    <shadedPattern>com.mpolder.dodgeball.valve</shadedPattern>
                                </relocation>
                            </relocations>
                        </configuration>
                    </execution>
                </executions>
            </plugin>
        </plugins>
    </build>

    <pluginRepositories>
        <pluginRepository>
            <id>maven-snapshots</id>
            <url>https://repository.apache.org/content/repositories/snapshots/</url>
        </pluginRepository>
    </pluginRepositories>

    <repositories>
        <repository>
            <id>spigot-repo</id>
            <url>https://hub.spigotmc.org/nexus/content/repositories/snapshots/</url>
        </repository>
        <repository>
            <id>sk89q-repo</id>
            <url>https://maven.enginehub.org/repo/</url>
        </repository>
    </repositories>

    <dependencies>
        <!-- https://mvnrepository.com/artifact/org.jetbrains/annotations -->
        <dependency>
            <groupId>org.jetbrains</groupId>
            <artifactId>annotations</artifactId>
            <version>22.0.0</version>
        </dependency>
        <dependency>
            <groupId>org.projectlombok</groupId>
            <artifactId>lombok</artifactId>
            <version>1.18.22</version>
        </dependency>
        <dependency>
            <groupId>org.spigotmc</groupId>
            <artifactId>spigot-api</artifactId>
            <version>1.16.5-R0.1-SNAPSHOT</version>
            <scope>provided</scope>
        </dependency>
        <dependency>
            <groupId>com.mpolder</groupId>
            <artifactId>Valve</artifactId>
            <version>1.0-SNAPSHOT</version>
            <scope>compile</scope>
        </dependency>
        <dependency>
            <groupId>com.sk89q.worldguard</groupId>
            <artifactId>worldguard-bukkit</artifactId>
            <version>7.0.7-SNAPSHOT</version>
            <scope>provided</scope>
        </dependency>
    </dependencies>
</project>

Valve pom.xml:

<?xml version="1.0" encoding="UTF-8"?>
<project xmlns="http://maven.apache.org/POM/4.0.0"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0</modelVersion>

    <groupId>com.mpolder</groupId>
    <artifactId>Valve</artifactId>
    <version>1.0-SNAPSHOT</version>

    <properties>
        <maven.compiler.source>16</maven.compiler.source>
        <maven.compiler.target>16</maven.compiler.target>
    </properties>

    <repositories>
        <repository>
            <id>spigot-repo</id>
            <url>https://hub.spigotmc.org/nexus/content/repositories/snapshots/</url>
        </repository>
    </repositories>

    <dependencies>
        <!-- https://mvnrepository.com/artifact/org.jetbrains/annotations -->
        <dependency>
            <groupId>org.jetbrains</groupId>
            <artifactId>annotations</artifactId>
            <version>22.0.0</version>
        </dependency>
        <!-- https://mvnrepository.com/artifact/org.reflections/reflections -->
        <dependency>
            <groupId>org.reflections</groupId>
            <artifactId>reflections</artifactId>
            <version>0.9.12</version>
        </dependency>
        <!-- https://mvnrepository.com/artifact/mysql/mysql-connector-java -->
        <dependency>
            <groupId>mysql</groupId>
            <artifactId>mysql-connector-java</artifactId>
            <version>8.0.27</version>
        </dependency>
        <!-- https://mvnrepository.com/artifact/org.jdbi/jdbi3-core -->
        <dependency>
            <groupId>org.jdbi</groupId>
            <artifactId>jdbi3-core</artifactId>
            <version>3.23.0</version>
        </dependency>
        <!-- https://mvnrepository.com/artifact/org.jdbi/jdbi3-core -->
        <dependency>
            <groupId>org.jdbi</groupId>
            <artifactId>jdbi3-sqlobject</artifactId>
            <version>3.23.0</version>
        </dependency>
        <dependency>
            <groupId>com.google.inject</groupId>
            <artifactId>guice</artifactId>
            <version>5.0.1</version>
        </dependency>
        <dependency>
            <groupId>org.spigotmc</groupId>
            <artifactId>spigot-api</artifactId>
            <version>1.16.5-R0.1-SNAPSHOT</version>
            <scope>provided</scope>
        </dependency>
    </dependencies>
</project>
morgwai
  • 2,513
  • 4
  • 25
  • 31
martijn p
  • 598
  • 4
  • 19
  • there's no way for anyone to say what's wrong without including your code (classes/methods from the stacktrace) and pom.xml – morgwai Dec 17 '21 at 13:26
  • @morgwai The actual project itself seems to be mostly unrelated. I'll add my pom.xml so its possible to see the actual jar shading. Aside from that its just using a very basic guice injection so I can't really share anything else – martijn p Jan 02 '22 at 13:36
  • @morgwai small clarification. In the original post my exception originated from simply trying to inject an interface that did not have a bound implementation. – martijn p Jan 02 '22 at 13:49
  • the pom was really helpful. It does seem really strange. since the class itself is in the jar as you pointed, this does not seem like a Guice problem. I'd rather some incorrect relocation issue during shading, which brings me to this question: why are you using snapshot version of `maven-shade-plugin`? you seem to be doing pretty standard stuff, so release should do, no? My instinct tells me that this is the main suspect of the whole problem. – morgwai Jan 02 '22 at 20:34
  • @morgwai From memory, I did this because of the fact that I'm developing on Java 16. I can check just to make sure that an older version indeed does not work, but vaguely remember running into problems with it – martijn p Jan 02 '22 at 20:55
  • Yes, does in fact result in an error: "Problem shading JAR ..... Unsupported class file major version 60". Googling gave me this StackOverflow (which I apparently used when I had this error last time): https://stackoverflow.com/a/68008625/5130640 – martijn p Jan 02 '22 at 20:57
  • ah snap... are you able check if it actually works with no shading at all? – morgwai Jan 02 '22 at 21:07
  • @morgwai With the way the project is set up currently, not easily. I might be able to execute it through my IDE if I write a main method for it. That won't be completely the same as the current project, but will see what'll happen. Will give it a try tomorrow, worth a shot :) – martijn p Jan 02 '22 at 21:13
  • 1
    @morgwai after months I think I've figured it out. I've asked a few others for help during that time and finally someone got me somewhere. I've updated an answer if you'd still like to know, but its not pretty :) – martijn p Feb 11 '22 at 00:27

1 Answers1

1

So, this will probably not be the solution anyone was hoping for (including me)

As it turns out, the library I was using called spigot (an extension on bukkit), has its own implementation of a classloader. This classloader just does not seem to function properly whatsoever, and fails to load the subclass even though the class is in the classpath.

The only way I could think of, once finding the cause of the problem, was to manually load in the class using Google Guava. This has fixed the issue, although in a very dirty way. It only needs to run once though, so I have stowed it away deep inside a method which name calls bukkit out on this bug.

If you'd like to know how I fixed it, prepare for a wild ride:

    List<String> toLoad = Arrays.asList(
            "com.google.inject.internal.Messages$FormatOptions",
            "com.google.inject.internal.util.LineNumbers",
            "com.google.inject.internal.util.LineNumbers$LineNumberReader",
            "com.google.inject.internal.PackageNameCompressor",
            "com.google.inject.internal.ErrorFormatter"
    );

    try {
        Set<ClassPath.ClassInfo> cp = ClassPath.from(ValvePlugin.class.getClassLoader()).getAllClasses();
        for (ClassPath.ClassInfo x : cp) {
            if (toLoad.contains(x.getName())) {
                x.load();
            }
        }
    } catch (IOException e) {
        e.printStackTrace();
    }

This code manually scans all the classes in the entire classpath (I couldn't find a quick way to scan only one package while also including subclasses) and loads in any names present in the list.

martijn p
  • 598
  • 4
  • 19
  • now that is a really messed up bug!! I hate ClassLoader mechanism in Java, btw: whenever someone implements his own, a kitten dies... ;-) – morgwai Mar 03 '22 at 20:04
  • I've updated the title and tags, so that it will be easier for others to find: I bet some ppl have already lost some of their hair because of this bug ;-] – morgwai Mar 03 '22 at 20:18