SBT add projectID to logs in multiproject build

Question

In an SBT multi-project build, when you run a task on an aggregator project and it runs the tasks in every aggregated subproject then all the logs from each subproject get output together in one big stream.

This makes it hard to debug build issues in a multi-project build as all the logs get mixed together. Is there a way to output the projectID on each log line so that you can quickly identify which subproject the log came from?

Here is an example project:

name := "my-multiproject-build"

lazy val ProjectOne = project
lazy val ProjectTwo = project

lazy val root = project.in( file(".") ).aggregate(ProjectOne, ProjectTwo)

(what happens by default)

sbt package

[info] Packaging ProjectOne.jar ...
[info] Done packaging.
[info] Packaging ProjectTwo.jar ...
[info] Done packaging.

(what I want)

sbt package

[info] [ProjectOne] Packaging ProjectOne.jar ...
[info] [ProjectOne] Done packaging.
[info] [ProjectTwo] Packaging ProjectTwo.jar ...
[info] [ProjectTwo] Done packaging.

I tried looking into SBT custom loggers, but unfortunately the documentation is a bit sparse and I'm by no means an SBT expert.

score 2 · Accepted Answer · answered Dec 19 '17 at 01:30

Like Rich said, there is currently no extension point to customize sbt's logging format. But if you don't mind relying on internal APIs you can get close to what you want, depending on which version of sbt you are using.

Basically you would have to replace the default logManager rather than adding extraLoggers (the API is similar though).

sbt 0.13.x

Our job here looks simpler. We can reuse BufferedLogger to avoid the boilerplate involved in delegating everything to a ConsoleLogger:

  logManager := LogManager.withScreenLogger { (_, state) =>
    val console = ConsoleLogger(state.globalLogging.console)
    new BufferedLogger(console) {
      val project = projectID.value.name
      override def log(level: Level.Value, message: => String): Unit =
        console.log(level, s"[$project] $message")
    }
  }

sbt 1.0.x

The logging API was changed here to provide event logging. We now have to provide a log4j Appender which is more flexible, but makes our job more difficult. We can't reuse the classes from sbt.internal where the logging implementation has moved, because they are all private, sealed, final, etc. The only thing I could think of short of duplicating the functionality of ConsoleAppender was to hack the output stream:

   logManager := LogManager.defaultManager(
    ConsoleOut.printStreamOut(new PrintStream(System.out) {
      val project = projectID.value.name
      override def println(str: String): Unit = {
        val (lvl, msg) = str.span(_ != ']')
        super.println(s"$lvl] [$project$msg")
      }
    }))

Note that there is no guarantee println will be called instead of some other print method.

I don't know if it's possible to use a log4j configuration file to customize the format.

Thanks for the detailed answer. It's unfortunate SBT does not provide this out of the box. For others who are curious how to set this up in the real world, you cannot set the `logManager` settingkey from a plugin as the individual subprojects will override the `logManager` value. Instead, you can make a shared function in your `project` directory and then call that function from each individual subproject to set the value of the `logManager` within each subproject. This ensures that you are overriding the default `logManager` value instead of the other way around. — gnicholas, Dec 20 '17 at 16:44

score 1 · Answer 2 · answered Dec 17 '17 at 23:59

Looking through the SBT code, I don't think this is possible nicely.

Here's a build.sbt which does most of what you want.

import sbt.Level
name := "my-multiproject-build"

lazy val ProjectOne = project
lazy val ProjectTwo = project

lazy val root = project.in( file(".") ).aggregate(ProjectOne, ProjectTwo)

val wrapLogger = (project: Project, inner: AbstractLogger) => {
  new AbstractLogger {

    override def log(level: Level.Value, message: => String): Unit = {
      inner.log(
        level,
        "[" + project.id + "] " + message
      )
    }

    override def setTrace(flag: Int): Unit = inner.setTrace(flag)

    override def setLevel(newLevel: Level.Value): Unit = {
      // MultiLogger keeps setting this to debug
      inner.setLevel(Level.Info)
    }

    override def setSuccessEnabled(flag: Boolean): Unit = inner.setSuccessEnabled(flag)

    override def logAll(events: Seq[LogEvent]): Unit = {
      events.foreach(log)
    }

    override def control(event: _root_.sbt.ControlEvent.Value, message: => String): Unit
      = inner.control(event, message)

    override def successEnabled: Boolean = inner.successEnabled

    override def getLevel = inner.getLevel

    override def getTrace: Int = inner.getTrace

    override def trace(t: => Throwable): Unit = inner.trace(t)

    override def success(message: => String): Unit = inner.success(message)
  }
}

extraLoggers in ProjectOne := {
  val currentFunction = extraLoggers.value
  (key: ScopedKey[_]) => {
    val logger = wrapLogger(ProjectOne, ConsoleLogger())
    logger.setLevel(Level.Info)
    logger +: currentFunction(key)
  }
}

extraLoggers in ProjectTwo := {
  val currentFunction = extraLoggers.value
  (key: ScopedKey[_]) => {
    val logger = wrapLogger(ProjectTwo, ConsoleLogger())
    logger.setLevel(Level.Info)
    logger +: currentFunction(key)
  }
}

The output is now duplicated for project-specific logs: once with the project name prepended and once without it. The output looks like:

[info] Done packaging.
[info] [ProjectTwo] Done packaging.
[info] Done updating.
[info] [ProjectOne] Done updating.

The ConsoleLogger is constructed at MainLogging.defaultScreen and there are no extension points which let you manipulate the log messages that I can see.

If SBT had used a logging library like logback or log4j2, rather than reinventing the wheel with its own logging framework, this would have been possible. :-(

SBT add projectID to logs in multiproject build

2 Answers2

sbt 0.13.x

sbt 1.0.x