sbt docker:publishLocal sporadically builds with the wrong version

[mrubin]

Expected behaviour

sbt docker:publishLocal always uses the correct version

Actual behaviour

sbt docker:publishLocal sporadically builds with the wrong version

Information

• Using sbt 1.1.2 on Mac.

We put the version number in our build.sbt file like so: version := "1.2.3" Most of the time, the correct version is used. However, sometimes, I see "SNAPSHOT" appearing in the build output and the version number from build.sbt is not used, despite being right there. This causes our docker image to have an unexpected name and fails our build.

How can I further debug this to see what's wrong?

[muuki88]

Do you have a minimal example to reproduce this? Are you having any custom auto plugins in your code? I haven't seen this anywhere before 😲

[mrubin]

@muuki88 I do not have any example that reproduces this 100% of the time. The issue happens sporadically. I understand that there may be some combination of settings in my project which is causing this that would be difficult to reproduce and I cannot give you my project. That is why it would be great to know how I can further debug this when it happens again - perhaps I could provide some debug output that would let you know what is happening.

An example build.sbt file is below. We run the following build command:

java -Dsbt.log.noformat=true -jar /usr/share/sbt/bin/sbt-launch.jar clean update compile test docker:publishLocal | tee "$TMP_FILE"

Just now we've had several failures in a row which produced the following output. The presence of SNAPSHOT in the output indicates that the build did not correctly figure out the version (even though it appears right there in build.sbt), which builds a Docker image with the wrong name and causes downstream steps in our build process to fail. Simply triggering another build (this is on Jenkins on linux) will fix the issue most of the time.

[info] Loading settings for project dev-foo-service-build from plugins.sbt ...
[info] Loading project definition from /var/lib/jenkins/workspace/dev-foo-service/project
[info] Loading settings for project dev-foo-service from build.sbt ...
[info] Set current project to dev-foo-service (in build file:/var/lib/jenkins/workspace/dev-foo-service/)
[info] Installing the s3:// URLStreamHandler via java.net.URL.setURLStreamHandlerFactory
[info] Creating a new Ivy URLHandlerDispatcher to handle s3:// URLs
[info] Executing in batch mode. For better performance use sbt's shell
[success] Total time: 0 s, completed Oct 18, 2018 2:44:39 PM
[info] Updating ...
[info] Done updating.
[success] Total time: 1 s, completed Oct 18, 2018 2:44:40 PM
[success] Total time: 0 s, completed Oct 18, 2018 2:44:40 PM
[success] Total time: 0 s, completed Oct 18, 2018 2:44:41 PM
[info] Packaging /var/lib/jenkins/workspace/dev-foo-service/target/scala-2.12/dev-foo-service_2.12-0.1.0-SNAPSHOT-sources.jar ...
[info] Packaging /var/lib/jenkins/workspace/dev-foo-service/target/scala-2.12/dev-foo-service_2.12-0.1.0-SNAPSHOT-javadoc.jar ...
[info] Done packaging.
[info] Done packaging.
[info] Packaging /var/lib/jenkins/workspace/dev-foo-service/target/scala-2.12/dev-foo-service_2.12-0.1.0-SNAPSHOT.jar ...
[info] Done packaging.
[info] Wrote /var/lib/jenkins/workspace/dev-foo-service/target/scala-2.12/dev-foo-service_2.12-0.1.0-SNAPSHOT.pom
[info] :: delivering :: default#dev-foo-service_2.12;0.1.0-SNAPSHOT :: 0.1.0-SNAPSHOT :: integration :: Thu Oct 18 14:44:41 UTC 2018
[info]  delivering ivy file to /var/lib/jenkins/workspace/dev-foo-service/target/scala-2.12/ivy-0.1.0-SNAPSHOT.xml
[info]  published dev-foo-service_2.12 to /var/lib/jenkins/.ivy2/local/default/dev-foo-service_2.12/0.1.0-SNAPSHOT/poms/dev-foo-service_2.12.pom
[info]  published dev-foo-service_2.12 to /var/lib/jenkins/.ivy2/local/default/dev-foo-service_2.12/0.1.0-SNAPSHOT/jars/dev-foo-service_2.12.jar
[info]  published dev-foo-service_2.12 to /var/lib/jenkins/.ivy2/local/default/dev-foo-service_2.12/0.1.0-SNAPSHOT/srcs/dev-foo-service_2.12-sources.jar
[info]  published dev-foo-service_2.12 to /var/lib/jenkins/.ivy2/local/default/dev-foo-service_2.12/0.1.0-SNAPSHOT/docs/dev-foo-service_2.12-javadoc.jar
[info]  published ivy to /var/lib/jenkins/.ivy2/local/default/dev-foo-service_2.12/0.1.0-SNAPSHOT/ivys/ivy.xml
[success] Total time: 0 s, completed Oct 18, 2018 2:44:41 PM

name := """foo-service"""

version := "1.0.123"

lazy val root = (project in file("."))
  .enablePlugins(PlayScala, LauncherJarPlugin, BuildInfoPlugin)
  .settings(
    buildInfoKeys := BuildInfoKey.ofN(name, version, scalaVersion, sbtVersion,
      "jenkinsBuildNumber" -> 0,
      "jenkinsBuildTag" -> "unknown",
      "jenkinsBuildUrl" -> "unknown",
      "jenkinsGitCommit" -> "unknown",
      "jenkinsBuildTimeChicago" -> "unknown",
      "jenkinsBuildTimeUTC" -> "unknown"
    ),
    buildInfoPackage := "buildinfo",
    buildInfoOptions += BuildInfoOption.BuildTime,
    buildInfoOptions += BuildInfoOption.ToMap,
    buildInfoOptions += BuildInfoOption.ToJson
  )

scalaVersion := "2.12.7"

evictionWarningOptions in update := EvictionWarningOptions.default
  .withWarnTransitiveEvictions(false)
  .withWarnDirectEvictions(false)

resolvers += "eaio.com" at "http://repo.eaio.com/maven2"
resolvers += "Sonatype OSS Snapshots" at "https://oss.sonatype.org/content/repositories/releases"

libraryDependencies += ws
libraryDependencies += guice
libraryDependencies += "com.amazonaws" % "aws-java-sdk" % "1.11.363"
libraryDependencies += javaJdbc
libraryDependencies += "mysql" % "mysql-connector-java" % "5.1.46"
libraryDependencies += "commons-codec" % "commons-codec" % "1.11"
libraryDependencies += "com.sun.mail" % "javax.mail" % "1.6.1"
libraryDependencies += "javax.mail" % "javax.mail-api" % "1.6.1"
libraryDependencies += "com.github.danielwegener" % "logback-kafka-appender" % "0.2.0-RC1"
libraryDependencies += "org.scalatest" % "scalatest_2.12" % "3.0.5" % "test"
libraryDependencies += "com.storm-enroute" %% "scalameter" % "0.8.2"
libraryDependencies += "com.malliina" %% "mobile-push" % "1.13.0"

testFrameworks += new TestFramework(implClassNames = "org.scalameter.ScalaMeterFramework")

parallelExecution in Test := false

import com.typesafe.sbt.packager.MappingsHelper._

mappings in Universal ++= directory(baseDirectory.value / "resources")

javaOptions in Universal ++= Seq(
  "-J-server",
  "-J-Xms64M",
  "-J-XX:+UnlockExperimentalVMOptions",
  "-J-XX:+UseCGroupMemoryLimitForHeap",
  "-J-XX:MaxRAMFraction=1",
  "-Dcom.sun.management.jmxremote=true",
  "-Dcom.sun.management.jmxremote.authenticate=false",
  "-Dcom.sun.management.jmxremote.ssl=false",
  "-Dcom.sun.management.jmxremote.port=9999",
  "-Dcom.sun.management.jmxremote.rmi.port=9999",
  "-Djava.rmi.server.hostname=127.0.0.1"
)

dockerBaseImage := "openjdk:8-jre-alpine"

import com.typesafe.sbt.packager.docker._

dockerCommands ++= Seq(
  Cmd("USER", "root"),
  Cmd("RUN", "apk", "--no-cache", "update"),
  Cmd("RUN", "apk", "--no-cache", "add", "bash"),
  Cmd("USER", "daemon"))

// https://tpolecat.github.io/2017/04/25/scalac-flags.html
scalacOptions ++= Seq(
  "-Ywarn-unused:imports",
  "-Ywarn-unused:locals",
  "-Ywarn-unused:params",
  "-Ywarn-unused:patvars",
  "-Ywarn-unused:privates")

[muuki88]

Thanks for adding a bit more information 😄

It seems that this is not sbt-native-packager related. Still I wonder why this is happening. What plugins do you have in your plugins.sbt and is there any other place the version setting is altered? Do you have any other *.sbt files in your project

[mrubin]

It seems that this is not sbt-native-packager related.

Do you think it's a core sbt issue? We typically use the following plugins:

com.typesafe.play sbt-plugin
org.javassist javassist
com.typesafe.sbt sbt-play-enhancer
com.eed3si9n sbt-buildinfo
com.frugalmechanic fm-sbt-s3-resolver

No other *.sbt files.

[mrubin]

@muuki88 Just ran into this on 4 builds in a row - it's blocking me from being able to deploy a production build.

What I can observe is that the version is set correctly, then things get to building the docker image and it's using "SNAPSHOT" instead of the correct version. Perhaps you're saying that by the time the version gets to sbt-native-packager, it's not set correctly. How can we debug this to see which scenario is occurring?

[mrubin]

@muuki88 Any thoughts/updates on this? Thank you.

[muuki88]

Unfortunately not 😣 and I don't have the time to investigate myself 😌 However I can try to act as a sparring partner here.

Is this the only project were this is happening?

[mrubin]

It sporadically happens in various projects (we have ~15 microservices, all with nearly the same setup). Where do you suspect the issue is? sbt? sbt-native-packager? Is there any debug output I can turn on in either one that might help determine why it's choosing SNAPSHOT when it has a version defined in build.sbt?

Thank you

[muuki88]

Usually you can call sbt show version and see the version printed.

I suspect the issue somewhere in your build setup 😁 a race condition in the setting intitialization code of sbt would have caused a lot more traction.
By your build, I also mean a specific set of plugins that may cause issues in combination.

What might shed a bit more light on this if you execute something like this

sbt "inspect version" "yourUsualBuildCommand"

[mrubin]

Thanks for that command! I will post what the output looks like in the normal case and when the issue happens again.

[mrubin]

When everything works correctly, the output of "inspect version" is as follows:

[info] Executing in batch mode. For better performance use sbt's shell
[info] Setting: java.lang.String = 1.16
[info] Description:
[info]  The version/revision of the current module.
[info] Provided by:
[info]  ProjectRef(uri("file:/var/lib/jenkins/workspace/my-service/"), "root") / Debian / version
[info] Defined at:
[info]  (com.typesafe.sbt.packager.debian.DebianPlugin.settings) DebianPlugin.scala:87
[info] Dependencies:
[info]  Linux / version
[info] Reverse dependencies:
[info]  Debian / debianPackageInfo
[info]  Debian / packageBin
[info]  Debian / target
[info] Delegates:
[info]  Debian / version
[info]  Linux / version
[info]  version
[info]  ThisBuild / Debian / version
[info]  ThisBuild / Linux / version
[info]  ThisBuild / version
[info]  Zero / Debian / version
[info]  Zero / Linux / version
[info]  Global / version
[info] Related:
[info]  Global / version
[info]  ThisBuild / version
[success] Total time: 0 s, completed Nov 9, 2018 9:35:37 PM

When the issue happens, the output is as follows:

[info] Executing in batch mode. For better performance use sbt's shell
[info] Setting: java.lang.String = 0.1.0-SNAPSHOT
[info] Description:
[info]  The version/revision of the current module.
[info] Provided by:
[info]  Global / version
[info] Defined at:
[info]  (sbt.Defaults.globalIvyCore) Defaults.scala:206
[info] Reverse dependencies:
[info]  isSnapshot
[info]  projectID
[info] Delegates:
[info]  version
[info]  ThisBuild / version
[info]  Global / version
[info] Related:
[info]  Global / version
[success] Total time: 0 s, completed Nov 9, 2018 9:34:08 PM

[dwickern]

@mrubin You'll see the second output if you run sbt "inspect version" in an empty directory. Maybe Travis is trying to build before your code is fully cloned?

[mrubin]

@dwickern prior to the sbt build command which produces the above output, the build script performs operations on build.sbt such as bumping the version by 1 and committing that back to git. So I don't think the issue is that the code is not fully cloned.

[muuki88]

Are you using sbt-dynver? https://github.com/dwijnand/sbt-dynver

If you change your build.sbt and commit it, then it's very likely there is a problem with the travis commands.

[mrubin]

We do use sbt-git for production builds, but for development builds we don’t use any such plugins and directly have the version set in build.sbt.

Both development and production builds have exhibited the issue, so I don’t think it’s related to git (or those kinds of plugins).

Our Jenkins builds issue the following command (this is on Linux):

java -Dsbt.log.noformat=true -jar /usr/share/sbt/bin/sbt-launch.jar clean update compile test docker:publishLocal

Is there anything wrong with that command?

Thank you very much.

[muuki88]

The command doesn't change the build.sbt? Do you have any snapshot dependencies? I wonder if the update is required. Never seen that being used.

[muuki88]

I also wonder why the version comes from

[info] Defined at:
[info]  (sbt.Defaults.globalIvyCore) Defaults.scala:206

the Defaults.scala. Also the working one is even more bizare.

[info] Defined at:
[info]  (com.typesafe.sbt.packager.debian.DebianPlugin.settings) DebianPlugin.scala:87

The debian plugin should not set the version, only the version in Debian.

Which it actually does: https://github.com/sbt/sbt-native-packager/blob/master/src/main/scala/com/typesafe/sbt/packager/debian/DebianPlugin.scala#L88

where and how to you set the version in your build.sbt? Is the version := "1.0.123" as posted in your example how the version is being set?

[mrubin]

Yes the version := "1.0.123" we have in build.sbt is how we set the version in our development builds. We don't have any other sbt files.

The above example for foo-service is a complete example that sporadically exhibits the issue.

[mrubin]

@muuki88 @dwickern Any further thoughts on this issue? It is still happening sporadically and makes those prod deployments fail.

[muuki88]

@mrubin how does the version := "x.y.z" end up in your build.sbt?
Is it commited this way or is a external script changing the build.sbt?

[mrubin]

It is committed this way.

[mrubin]

@muuki88 Anything else I can try for this?

[muuki88]

I have ran out of ideas 😢

[nemo83]

@muuki88 where are you running your build? I'm currently experiencing an issue when building sbt project on amazon-ami for eks.

[muuki88]

I don't do docker 🤪 ( yet )