IndexOutOfBoundsException in LogFactory

[freyacodes]

We've been using Togglz in our open source project for well over a year, and we have recently done a lot of work to refactor our code. After over 250 commits we have started testing in a staging environment in which Togglz fails with this exception:

Caused by: java.lang.IndexOutOfBoundsException: Index 0 out-of-bounds for length 0
        at java.base/jdk.internal.util.Preconditions.outOfBounds(Preconditions.java:64)
        at java.base/jdk.internal.util.Preconditions.outOfBoundsCheckIndex(Preconditions.java:70)
        at java.base/jdk.internal.util.Preconditions.checkIndex(Preconditions.java:248)
        at java.base/java.util.Objects.checkIndex(Objects.java:372)
        at java.base/java.util.ArrayList.get(ArrayList.java:440)
        at org.togglz.core.logging.LogFactory.getLogProvider(LogFactory.java:37)
        at org.togglz.core.logging.LogFactory.getLog(LogFactory.java:27)
        at org.togglz.core.logging.LogFactory.getLog(LogFactory.java:23)
        at org.togglz.core.repository.file.FileBasedStateRepository.<clinit>(FileBasedStateRepository.java:22)
        ... 15 more

This exception only occurs after we build our project using Gradle. This means that it doesn't affect our automated testing, and we have no idea what particular commit in our project broke Togglz.

We use SLF4J as our logging facade. The only significant change to our Gradle build configs seems to only be the addition of Kotlin, and I don't believe we have changed how we interact with Togglz.

Any ideas as to why this is happening?

[ruifigueira]

Did you include org.togglz:togglz-slf4j as a dependency?

[freyacodes]

No we didn't. I suspect we were using the Jdk14LogProvider implementation before, and now it isn't loading for some reason.

I added togglz-slf4j but we are still getting the same exception.

[ruifigueira]

Can you also check that the corresponding togglz-slf4j jar can be found in the staging environment classpath?

Nevertheless, it's strange because it should always have the JDK14LogProvider available (it's provided in togglz-core).

Are you using OpenJDK 9+?

[freyacodes]

I'm using Oracle JDK 10, and I also tried Oracle JDK 9 earlier. The jar is found in the resulting uberjar after extracting it

[ruifigueira]

And when it was still working, were you already using OpenJDK 9+? I'm trying to determine if it's related with changes introduced in JDK 9+, like modules.

[freyacodes]

We use Oracle JDK 10 in production, where togglz still works

[chkal]

Not sure why the ServiceLoader mechanism doesn't work. The only issues I'm aware of are:

• OSGi doesn't support ServiceLoader AFAIK
• The ServiceLoader uses the context class loader. I ran into issues regarding this with OpenLiberty, because the context class loader was a different one during application bootstrap.

JDK10 should't really be an issue. Togglz doesn't contain a module descriptor yet.

[chkal]

Any chance that you could debug which ClassLoader the ServiceLoader uses when looking for the LogProvider?

[freyacodes]

I'm having trouble with that. IDEA's remote debugger won't recognize this method My IDE was using JDK 9

Maybe it is a problem with how the Spring Boot Gradle plugin packages jars?

[chkal]

Are you running from a fat jar? In this case, yes, this could be an issue.

Could you check if there is a file called META-INF/services/org.togglz.core.spi.LogProvider in the archive?

https://github.com/togglz/togglz/blob/master/core/src/main/resources/META-INF/services/org.togglz.core.spi.LogProvider

[freyacodes]

The service directory is located in the inner jar, eg /BOOT-INF/lib/togglz-core-2.6.0.Final.jar/META-INF/services

However, the same goes for our working builds as well.

[chkal]

Could you perhaps post the full stacktrace? Including all the caused by blocks?

[chkal]

And it would also be interesting to know what you changed as part of your refactoring. Maybe any key things? Spring Boot updates? Other JVM or container updates?

[freyacodes]

• Too many things were changed to list
  
• The only significant thing that changed to our build process (as far as I can see) was the addition of Kotlin, which I concluded after looking at the blame of our parent gradle config, and our module gradle config.
• Old builds still work with the same JVM (Oracle JDK 10)
• Not sure what you mean with container updates, but it happens inside and outside of Docker

This is the full exception. I omitted the first part because our stack is probably irrelevant:

Exception in thread "ForkJoinPool.commonPool-worker-29" java.lang.ExceptionInInitializerError
        at fredboat.feature.togglz.FeatureConfig$FeatureManagerHolder.<clinit>(FeatureConfig.java:60)
        at fredboat.feature.togglz.FeatureConfig.getTheFeatureManager(FeatureConfig.java:49)
        at fredboat.feature.togglz.FeatureFlags.isActive(FeatureFlags.java:47)
        at fredboat.commandmeta.CommandManager.prefixCalled$suspendImpl(CommandManager.kt:68)
        at fredboat.commandmeta.CommandManager.prefixCalled(CommandManager.kt)
        at fredboat.event.MessageEventHandler.limitOrExecuteCommand(MessageEventHandler.kt:137)
        at fredboat.event.MessageEventHandler$onGuildMessage$1.doResume(MessageEventHandler.kt:123)
        at kotlin.coroutines.experimental.jvm.internal.CoroutineImpl.resume(CoroutineImpl.kt:42)
        at kotlin.coroutines.experimental.jvm.internal.CoroutineImpl.resume(CoroutineImpl.kt:41)
        at kotlinx.coroutines.experimental.DispatchedTask$DefaultImpls.run(Dispatched.kt:161)
        at kotlinx.coroutines.experimental.AbstractContinuation.run(AbstractContinuation.kt:31)
        at java.base/java.util.concurrent.ForkJoinTask$RunnableExecuteAction.exec(ForkJoinTask.java:1426)
        at java.base/java.util.concurrent.ForkJoinTask.doExec(ForkJoinTask.java:290)
        at java.base/java.util.concurrent.ForkJoinPool.runWorker(ForkJoinPool.java:1603)
        at java.base/java.util.concurrent.ForkJoinWorkerThread.run(ForkJoinWorkerThread.java:177)
Caused by: java.lang.IndexOutOfBoundsException: Index 0 out-of-bounds for length 0
        at java.base/jdk.internal.util.Preconditions.outOfBounds(Preconditions.java:64)
        at java.base/jdk.internal.util.Preconditions.outOfBoundsCheckIndex(Preconditions.java:70)
        at java.base/jdk.internal.util.Preconditions.checkIndex(Preconditions.java:248)
        at java.base/java.util.Objects.checkIndex(Objects.java:372)
        at java.base/java.util.ArrayList.get(ArrayList.java:440)
        at org.togglz.core.logging.LogFactory.getLogProvider(LogFactory.java:37)
        at org.togglz.core.logging.LogFactory.getLog(LogFactory.java:27)
        at org.togglz.core.logging.LogFactory.getLog(LogFactory.java:23)
        at org.togglz.core.repository.file.FileBasedStateRepository.<clinit>(FileBasedStateRepository.java:22)
        ... 15 more

[freyacodes]

One of my collaborators figured we were missing a dependency. This should fix it: Frederikam/Fredboat@e0db37b

Thanks for helping us fix this 😄

I still wonder what caused it to break when it was working before

Edit: For the record, it seems that it had to do with Togglz using the default classloader, instead of the one provided by Spring Boot

[chkal]

Thanks for letting us know what the problem was. Although I'm also not sure why this error occurred just because of the missing Spring Boot module.