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

[scottfrederick]

@gutschet Thanks for the additional info. I was curious if you were running something other than Docker Engine, or an older Docker Engine, or something else that might cause the daemon to give responses that are different from what we see in our testing. Docker Engine 20.10.5 is close to what we use, so that's not likely to be part of the root cause. As @philwebb said, this is difficult for us to reproduce to come up with a fix. If it is possible to provide logs as @nils-christian stated above that would be helpful.

[spring-projects-issues]

If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.

[spring-projects-issues]

Closing due to lack of requested feedback. If you would like us to look at this issue, please provide the requested information and we will re-open the issue.

[philwebb]

Reopening because even without the sample it’s probably worth guarding against the exception.

[mhalbritter]

I submitted a PR which ignores events with an invalid stream type: #29675

[philwebb]

Thanks @mhalbritter. Closing in favor of PR #29675