A simple non-static logger for Scala

Overview

Here’s an idea for a logger that doesn’t rely on it being shared statically. Initialization is done using implicits, which results in less typing when using the actual classes that mixin the Loggable trait. Any object created within such classes will also get access to these implicits. This lets the implicit arguments propagate forward to other loggable objects when instanciated inside a Loggable class.

The Loggable trait

The trait defines several logging methods such as info(), warn(), error(), fail(), and debug(), where error() will return false and fail() will result in an AssertionError exception being thrown. Each method specify who triggered the logging method, where in the sourcecode it happend, the message that was sent, and a list of zero or more application-defined tags. The tags can be used for example to do filtering or add extra logging categories in the implementation of the logging methods.

Three members controls the behaviour of the Loggable trait. The getLogCompanion specify the companion object who contains the object’s debug tags, the logger.checker checks that debug logging is enabled using the companion’s debug tags, and the logger.writer outputs the logged messages.

The whole process is bootstrapped by constructing an object that implements the Logger trait and marking it as implicit. This could be done for example in an application object or in the main() method.

import java.io.{PrintWriter,StringWriter}
import java.util.regex.{Pattern,Matcher}
 
trait Loggable[+T <: Loggable[T]] {
  this: T => // type this trait with the subclass that uses it
 
  import Loggable._
 
  // attributes required by this trait
  protected val logger: Logger
 
  // methods required by this trait
  protected def getLogCompanion(): LogCompanion[T]
 
  // predefined methods
  protected final def error(msg: String, tags: String*): Boolean = {
    val trace = (new Exception).getStackTrace()(2)
    val who   = toDot(trace.getClassName) + "." + toDot(trace.getMethodName)
    val where = trace.getFileName + ":" + trace.getLineNumber
    logger.writer.error(msg,who,where,tags:_*)
  }
 
  protected final def error(exp: Throwable, tags: String*): Boolean = {
    val trace = (new Exception).getStackTrace()(2)
    val who   = toDot(trace.getClassName) + "." + toDot(trace.getMethodName)
    val where = trace.getFileName + ":" + trace.getLineNumber
    logger.writer.error(expToString(exp),who,where,tags:_*)
  }
 
  protected final def fail(msg: String, tags: String*): Nothing = {
    val trace = (new Exception).getStackTrace()(2)
    val who   = toDot(trace.getClassName) + "." + toDot(trace.getMethodName)
    val where = trace.getFileName + ":" + trace.getLineNumber
    logger.writer.fail(msg,who,where,tags:_*)
  }
 
  protected final def debug(msg: String, tags: String*) {
    // the tag "all" controls all debug logging
    if (logger.checker("all") &&
        getLogCompanion.DebugTags.exists(tag => logger.checker(tag))) {
      val trace = (new Exception).getStackTrace()(2)
      val who   = toDot(trace.getClassName) + "." + toDot(trace.getMethodName)
      val where = trace.getFileName + ":" + trace.getLineNumber
      logger.writer.debug(msg,who,where,tags:_*)
    }
  }
 
  protected final def info(msg: String, tags: String*) {
    val trace = (new Exception).getStackTrace()(2)
    val who   = toDot(trace.getClassName) + "." + toDot(trace.getMethodName)
    val where = trace.getFileName + ":" + trace.getLineNumber
    logger.writer.info(msg,who,where,tags:_*)
  }
 
  protected final def warn(msg: String, tags: String*) {
    val trace = (new Exception).getStackTrace()(2)
    val who   = toDot(trace.getClassName) + "." + toDot(trace.getMethodName)
    val where = trace.getFileName + ":" + trace.getLineNumber
    logger.writer.warn(msg,who,where,tags:_*)
  }
}
 
object Loggable {
 
  // traits required by Loggable
  trait LogCompanion[+T <: Loggable[_]] {
    val DebugTags: Set[String]
  }
 
  trait Logger {
    val checker: LogChecker
    val writer: LogWriter
  }
 
  trait LogChecker {
    def update(tag: String, isEnabled: Boolean): Unit
    def apply(tag: String): Boolean
  }
 
  trait LogWriter {
      def debug(msg: String, who: String, where: String,tags: String*): Unit
      def error(msg: String, who: String, where: String, tags: String*): Boolean
      def fail(msg: String, who: String, where: String, tags: String*): Nothing
      def info(msg: String, who: String, where: String, tags: String*): Unit
      def warn(msg: String, who: String, where: String, tags: String*): Unit
  }
 
  // utility function
  private val SlashPattern = Pattern.compile("\\\\")
 
  private def toDot(str: String): String = {
    val matcher = SlashPattern.matcher(str)
    matcher.replaceAll(".")
  }
 
  private def expToString(exp: Throwable): String = {
    val writer = new StringWriter
    exp.printStackTrace(new PrintWriter(writer))
    writer.toString
  }
}

An example of how the trait could be used

import Loggable._
 
// common trait for tunes that Jukebox can use
trait Playable {
  this: Loggable[_] =>
 
  def play(): Unit = info("Started playing " + this)
  def stop(): Unit = info("Stopped playing " + this)
}
 
// the secondary implicit list of arguments are resolved at compile-time by
// the compiler, which will replace these arguments with any available implicitly
// defined objects that satisfy the type. Multiple objects are resolved by using
// the most specific one. There are also rules for how the compiler does search.
class Jukebox()(implicit protected val logger: Logger)
  extends Loggable[Jukebox] {
 
  import scala.collection.immutable.Queue
 
  protected var tunes = Queue[Playable]()
 
  debug("Created " + this)
 
  override def toString(): String = "(Jukebox tunes: " + tunes.mkString("[",",","]") + ")"
 
  protected def getLogCompanion(): LogCompanion[Jukebox] = Jukebox
 
  def queue(tune: Playable) {
    tunes = tunes.enqueue(tune)
    debug("Queued " + tune + " on " + this)
  }
 
  def kick(): Unit = fail("Crashed " + this)
 
  def play() {
    if (tunes.isEmpty)
      return warn("No more tunes to play on " + this)
 
    val (tune,rest) = tunes.dequeue
    tunes = rest
    tune.play()
    tune.stop()
  }
}
 
object Jukebox extends LogCompanion[Jukebox] {
  val DebugTags = Set("jukebox")
}
 
class Song(val name: String)(implicit protected val logger: Logger)
  extends Playable with Loggable[Song] {
 
  debug("Created " + this)
  override def toString(): String = "(Song name: \"" + name + "\")"
  protected def getLogCompanion(): LogCompanion[Song] = Song
}
 
object Song extends LogCompanion[Song] {
  val DebugTags = Set("song")
}
 
// override the logCompanion of Song
class Jingle(name0: String)(implicit logger: Logger)
  extends Song(name0) {
  debug("Created " + this)
  override def toString(): String = "(Jingle name: \"" + name + "\")"
  override protected def getLogCompanion(): LogCompanion[Song] = Jingle
}
 
object Jingle extends LogCompanion[Jingle] {
  val DebugTags = Set("jingle") ++ Song.DebugTags
}

Running the example code with some objects

// instantiating the logging  checker and writer
implicit val logger = new Logger {
  var enabledTags = Set("all","song","jukebox","jingle")
  var disabledTags = Set()
 
  val checker = new LogChecker {
    def update(tag: String, isEnabled: Boolean) {
      enabledTags = if (isEnabled) enabledTags + tag else enabledTags - tag
    }
    def apply(tag: String): Boolean = enabledTags contains tag
  }
 
  val writer = new LogWriter {
    def debug(msg: String, who: String, where: String, tags: String*) {
      println("\n--debug " + who + " " + where + "\n" + msg)
    }
    def error(msg: String, who: String, where: String, tags: String*): Boolean = {
      println("--error " + who + " " + where + "\n" + msg)
      false
    }
    def fail(msg: String, who: String, where: String, tags: String*): Nothing = {
      println("\n--fail " + who + " " + where + "\n" + msg)
      throw new java.lang.AssertionError(
        "msg: " + msg + " who: " + who + " where: " + where
      )
    }
    def info(msg: String, who: String, where: String, tags: String*) {
      println("\n--info " + who + " " + where + "\n" + msg)
    }
    def warn(msg: String, who: String, where: String, tags: String*) {
      println("\n--warn " + who + " " + where + "\n" + msg)
    }
  }
}
 
// creating some test objects
val jukebox = new Jukebox
jukebox.queue(new Song("that ol' tune"))
jukebox.queue(new Song("dum di dum"))
jukebox.queue(new Jingle("snap! snap!"))
jukebox.play()
jukebox.play()
jukebox.play()
jukebox.play()
jukebox.kick()

The resulting output in the console

--debug Main$$anon$4$Jukebox.<init> Debug.scala:123
Created (Jukebox tunes: [])
 
--debug Main$$anon$4$Song.<init> Debug.scala:153
Created (Song name: "that ol' tune")
 
--debug Main$$anon$4$Jukebox.queue Debug.scala:129
Queued (Song name: "that ol' tune") on (Jukebox tunes: [(Song name: "that ol' tune")])
 
--debug Main$$anon$4$Song.<init> Debug.scala:153
Created (Song name: "dum di dum")
 
--debug Main$$anon$4$Jukebox.queue Debug.scala:129
Queued (Song name: "dum di dum") on (Jukebox tunes: [(Song name: "that ol' tune"),(Song name: "dum di dum")])
 
--debug Main$$anon$4$Song.<init> Debug.scala:153
Created (Jingle name: "snap! snap!")
 
--debug Main$$anon$4$Jingle.<init> Debug.scala:166
Created (Jingle name: "snap! snap!")
 
--debug Main$$anon$4$Jukebox.queue Debug.scala:129
Queued (Jingle name: "snap! snap!") on (Jukebox tunes: [(Song name: "that ol' tune"),(Song name: "dum di dum"),(Jingle name: "snap! snap!")])
 
--info Main$$anon$4$Playable$class.play Debug.scala:107
Started playing (Song name: "that ol' tune")
 
--info Main$$anon$4$Playable$class.stop Debug.scala:108
Stopped playing (Song name: "that ol' tune")
 
--info Main$$anon$4$Playable$class.play Debug.scala:107
Started playing (Song name: "dum di dum")
 
--info Main$$anon$4$Playable$class.stop Debug.scala:108
Stopped playing (Song name: "dum di dum")
 
--info Main$$anon$4$Playable$class.play Debug.scala:107
Started playing (Jingle name: "snap! snap!")
 
--info Main$$anon$4$Playable$class.stop Debug.scala:108
Stopped playing (Jingle name: "snap! snap!")
 
--warn Main$$anon$4$Jukebox.play Debug.scala:136
No more tunes to play on (Jukebox tunes: [])
 
--fail Main$$anon$4$Jukebox.kick Debug.scala:133
Crashed (Jukebox tunes: [])
java.lang.AssertionError: msg: Crashed (Jukebox tunes: []) who: Main$$anon$4$Jukebox.kick where: Debug.scala:133
        at Main$$anon$4$$anon$1$$anon$3.fail(Debug.scala:197)
        at Main$$anon$4$Loggable$class.fail(Debug.scala:33)
        at Main$$anon$4$Jukebox.fail(Debug.scala:116)
        at Main$$anon$4$Jukebox.kick(Debug.scala:133)
        at Main$$anon$4.<init>(Debug.scala:219)
        at Main$.main(Debug.scala:1)
        at Main.main(Debug.scala)
        ...

Some notes on the logger solution

I didn’t find any good solution on handling inherited DebugTags in the LogCompanion objects. These must instead be copied manually in the code of the companion object.

I considered using call-by-name on the debug argument but it wasn’t worth it. Per info from scala mailing list, it would result in an anonymous inner class and object instantiation at each place a debug call would be done, which clearly defeats the purpose of using call-by-name to only calculate the message when needed.

References

Leave a Reply

Your email address will not be published. Required fields are marked *