build-image fails sometimes with ArrayIndexOutOfBoundsException

[nils-christian]

Hi,

We are experiencing an ArrayIndexOutOfBoundsException in some very rare cases while building our image with the spring-boot-maven-plugin. We are using Spring Boot 2.4.6. Unfortunately we cannot provide an example project, because the error cannot be reproduced. It happens in something like 1 of 50 builds. Can we somehow do something for a better analysis? Is there a possible root cause?

Best regards

Nils

10:05:11  org.apache.maven.lifecycle.LifecycleExecutionException: Failed to execute goal org.springframework.boot:spring-boot-maven-plugin:2.4.6:build-image (default) on project XYZ: Execution default of goal org.springframework.boot:spring-boot-maven-plugin:2.4.6:build-image failed: Index 3 out of bounds for length 3
10:05:11      at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:215)
10:05:11      at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:156)
10:05:11      at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:148)
10:05:11      at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:117)
10:05:11      at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:81)
10:05:11      at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build (SingleThreadedBuilder.java:56)
10:05:11      at org.apache.maven.lifecycle.internal.LifecycleStarter.execute (LifecycleStarter.java:128)
10:05:11      at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:305)
10:05:11      at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:192)
10:05:11      at org.apache.maven.DefaultMaven.execute (DefaultMaven.java:105)
10:05:11      at org.apache.maven.cli.MavenCli.execute (MavenCli.java:957)
10:05:11      at org.apache.maven.cli.MavenCli.doMain (MavenCli.java:289)
10:05:11      at org.apache.maven.cli.MavenCli.main (MavenCli.java:193)
10:05:11      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0 (Native Method)
10:05:11      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke (NativeMethodAccessorImpl.java:62)
10:05:11      at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke (DelegatingMethodAccessorImpl.java:43)
10:05:11      at java.lang.reflect.Method.invoke (Method.java:566)
10:05:11      at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced (Launcher.java:282)
10:05:11      at org.codehaus.plexus.classworlds.launcher.Launcher.launch (Launcher.java:225)
10:05:11      at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode (Launcher.java:406)
10:05:11      at org.codehaus.plexus.classworlds.launcher.Launcher.main (Launcher.java:347)
10:05:11  Caused by: org.apache.maven.plugin.PluginExecutionException: Execution default of goal org.springframework.boot:spring-boot-maven-plugin:2.4.6:build-image failed: Index 3 out of bounds for length 3
10:05:11      at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:148)
10:05:11      at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:210)
10:05:11      at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:156)
10:05:11      at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:148)
10:05:11      at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:117)
10:05:11      at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:81)
10:05:11      at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build (SingleThreadedBuilder.java:56)
10:05:11      at org.apache.maven.lifecycle.internal.LifecycleStarter.execute (LifecycleStarter.java:128)
10:05:11      at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:305)
10:05:11      at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:192)
10:05:11      at org.apache.maven.DefaultMaven.execute (DefaultMaven.java:105)
10:05:11      at org.apache.maven.cli.MavenCli.execute (MavenCli.java:957)
10:05:11      at org.apache.maven.cli.MavenCli.doMain (MavenCli.java:289)
10:05:11      at org.apache.maven.cli.MavenCli.main (MavenCli.java:193)
10:05:11      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0 (Native Method)
10:05:11      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke (NativeMethodAccessorImpl.java:62)
10:05:11      at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke (DelegatingMethodAccessorImpl.java:43)
10:05:11      at java.lang.reflect.Method.invoke (Method.java:566)
10:05:11      at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced (Launcher.java:282)
10:05:11      at org.codehaus.plexus.classworlds.launcher.Launcher.launch (Launcher.java:225)
10:05:11      at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode (Launcher.java:406)
10:05:11      at org.codehaus.plexus.classworlds.launcher.Launcher.main (Launcher.java:347)
10:05:11  Caused by: java.lang.ArrayIndexOutOfBoundsException: Index 3 out of bounds for length 3
10:05:11      at org.springframework.boot.buildpack.platform.****.LogUpdateEvent.read (LogUpdateEvent.java:93)
10:05:11      at org.springframework.boot.buildpack.platform.****.LogUpdateEvent.readAll (LogUpdateEvent.java:79)
10:05:11      at org.springframework.boot.buildpack.platform.****.DockerApi$ContainerApi.logs (DockerApi.java:338)
10:05:11      at org.springframework.boot.buildpack.platform.build.Lifecycle.run (Lifecycle.java:163)
10:05:11      at org.springframework.boot.buildpack.platform.build.Lifecycle.execute (Lifecycle.java:119)
10:05:11      at org.springframework.boot.buildpack.platform.build.Builder.executeLifecycle (Builder.java:193)
10:05:11      at org.springframework.boot.buildpack.platform.build.Builder.build (Builder.java:103)
10:05:11      at org.springframework.boot.maven.BuildImageMojo.buildImage (BuildImageMojo.java:222)
10:05:11      at org.springframework.boot.maven.BuildImageMojo.execute (BuildImageMojo.java:212)
10:05:11      at org.apache.maven.plugin.DefaultBuildPluginManager.executeMojo (DefaultBuildPluginManager.java:137)
10:05:11      at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:210)
10:05:11      at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:156)
10:05:11      at org.apache.maven.lifecycle.internal.MojoExecutor.execute (MojoExecutor.java:148)
10:05:11      at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:117)
10:05:11      at org.apache.maven.lifecycle.internal.LifecycleModuleBuilder.buildProject (LifecycleModuleBuilder.java:81)
10:05:11      at org.apache.maven.lifecycle.internal.builder.singlethreaded.SingleThreadedBuilder.build (SingleThreadedBuilder.java:56)
10:05:11      at org.apache.maven.lifecycle.internal.LifecycleStarter.execute (LifecycleStarter.java:128)
10:05:11      at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:305)
10:05:11      at org.apache.maven.DefaultMaven.doExecute (DefaultMaven.java:192)
10:05:11      at org.apache.maven.DefaultMaven.execute (DefaultMaven.java:105)
10:05:11      at org.apache.maven.cli.MavenCli.execute (MavenCli.java:957)
10:05:11      at org.apache.maven.cli.MavenCli.doMain (MavenCli.java:289)
10:05:11      at org.apache.maven.cli.MavenCli.main (MavenCli.java:193)
10:05:11      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0 (Native Method)
10:05:11      at jdk.internal.reflect.NativeMethodAccessorImpl.invoke (NativeMethodAccessorImpl.java:62)
10:05:11      at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke (DelegatingMethodAccessorImpl.java:43)
10:05:11      at java.lang.reflect.Method.invoke (Method.java:566)
10:05:11      at org.codehaus.plexus.classworlds.launcher.Launcher.launchEnhanced (Launcher.java:282)
10:05:11      at org.codehaus.plexus.classworlds.launcher.Launcher.launch (Launcher.java:225)
10:05:11      at org.codehaus.plexus.classworlds.launcher.Launcher.mainWithExitCode (Launcher.java:406)
10:05:11      at org.codehaus.plexus.classworlds.launcher.Launcher.main (Launcher.java:347)

[philwebb]

From the stacktrace it looks like this is in the low level code that reads Docker log messages. It looks like we're reading an incorrect stream type value somehow. It's going to be hard to replicate, but we can at least guard against the failure and continue.

@nils-christian Do the logs look correct on failed builds?

[scottfrederick]

@nils-christian Can you provide any additional details about the environment the image build runs in, like the operating system, whether you are using Docker Engine or another Docker daemon, etc?

[nils-christian]

Hi @philwebb,

Currently we do not save the log files. We changed that so that we can check them the next time the issue occures.

Best regards,

Nils

[gutschet]

Hello @scottfrederick,
Here some details about the environment:

• build is running in a jenkins agent in docker container in a kubernetes cluster
• build agent container base image is debian (:buster and :bullseye both show the error)
• maven 3.6.3
• openjdk 11.0.9.1
• kubernetes cluster version 1.20.4
• docker engine on the nodes 20.10.5
• operating system of clusternodes is debian buster

If you need any more information, please feel free to ask.

Best regards
Timo