Structured DSL

Structured logging is the basis for logging rich events. Blindsight comes with an internal DSL which lets you work with Scala types intuitively while ensuring that you cannot produce an invalid structure. Internally, the DSL is rendered using MarkersResolver and ArgumentResolver to Markers and StructuredArguments, using the ServiceLoader pattern. This approach produces ideomatic structured output for both line oriented encoders and JSON encoders.

The default implementation is provided with blindsight-logstash module, through LogstashArgumentResolver and LogstashMarkersResolver. You must configure a JSON encoder to render JSON output. See Terse Logback and the Terse Logback Showcase for examples of how to configure logstash-logback-encoder for JSON.

Constructing DSL

Primitive types map to primitives. Any seq produces JSON array.

val json: BArray = List(1, 2, 3)

• Tuple2[String, A] produces a field.

val field: BField = ("name" -> "joe")

• ~ operator produces object by combining fields.

val bobject: BObject = ("name" -> "joe") ~ ("age" -> 35)

• ~~ operator works the same as ~ and is useful in situations where ~ is shadowed, eg. when using Spray or akka-http.

val bobject: BObject = ("name" -> "joe") ~~ ("age" -> 35)

Representing Times

You will want to be consistent and organized about how you represent your field names, and you will typically want to include a representation of the unit used a scalar quantity, particularly time-based fields. Honeycomb suggests a suffix with unit quantity – _ms, _sec, _ns, _µs, etc.

This also follows for specific points in time. If you represent an instant as a time since epoch, use _tse along with the unit, i.e. milliseconds since epoch is created_tse_ms:

copysourcelogger.info("time = {}", bobj("created_tse_ms" -> Instant.now.toEpochMilli))

If you represent an instant in RFC 3339 / ISO 8601 format (ideally in UTC), use "_ts", i.e. created_ts:

copysourcelogger.info("time = {}", bobj("created_ts" -> Instant.now.toString))

If you are representing a duration, then specify _dur and the unit, i.e. a backoff duration between retries may be backoff_dur_ms=150.

copysourceval backoffDuration = 150
// // assume we call after(backoffDuration, task) etc...
logger.info("backoff duration = {}", bobj("backoff_dur_ms" -> backoffDuration))

If you are using Java durations, then use dur_iso and the ISO-8601 duration format PnDTnHnMn.nS, i.e. the duration of someone’s bike ride may be ride_dur_iso="PT2H15M"

copysourceval rideDuration = Duration.parse("PT2H15M")
logger.info("backoff duration = {}", bobj("ride_dur_iso" -> rideDuration.toString))

This is because both JSON and logfmt do not come with any understanding of dates themselves, and logs are not always kept under tight control under a schema. Keeping the units explicit lets the logs be self-documenting. Using JSON-LD can be more convenient, as there is a built-in understanding of date formatting with typed values.

Representing Complex Data

Using the DSL works very well with ToArgument and ToMarkers, because there is a type class instance for BObject. Here’s a fully worked example:

copysourceimport com.tersesystems.blindsight.AST._
import com.tersesystems.blindsight.DSL._
import com.tersesystems.blindsight.{LoggerFactory, _}

object DSLExample {
  private val logger = LoggerFactory.getLogger

  def main(args: Array[String]): Unit = {
    val winners =
      List(Winner(23, List(2, 45, 34, 23, 3, 5)), Winner(54, List(52, 3, 12, 11, 18, 22)))
    val lotto = Lotto(5, List(2, 45, 34, 23, 7, 5, 3), winners, None)
    logger.info("message {}", lotto)
  }

  case class Winner(id: Long, numbers: List[Int]) {
    lazy val asBObject: BObject = ("winner-id" -> id) ~ ("numbers" -> numbers)
  }

  object Winner {
    implicit val toArgument: ToArgument[Winner] = ToArgument { w => Argument(w.asBObject) }
  }

  case class Lotto(
      id: Long,
      winningNumbers: List[Int],
      winners: List[Winner],
      drawDate: Option[java.util.Date]
  ) {
    lazy val asBObject: BObject = "lotto" ->
      ("lotto-id"        -> id) ~
      ("winning-numbers" -> winningNumbers) ~
      ("draw-date"       -> drawDate.map(_.toString)) ~
      ("winners"         -> winners.map(w => w.asBObject))
  }

  object Lotto {
    implicit val toArgument: ToArgument[Lotto] = ToArgument { lotto => Argument(lotto.asBObject) }
  }
}

This produces the following:

Fg91NlmNpRodHaINzdiAAA 9:45:57.374 [INFO ] e.d.D.main logger -  message {lotto={lotto-id=5, winning-numbers=[2, 45, 34, 23, 7, 5, 3], draw-date=null, winners=[{winner-id=23, numbers=[2, 45, 34, 23, 3, 5]}, {winner-id=54, numbers=[52, 3, 12, 11, 18, 22]}]}}

in JSON:

{
  "id": "Fg91NlmNpRodHaINzdiAAA",
  "relative_ns": -135695,
  "tse_ms": 1589820357374,
  "@timestamp": "2020-05-18T16:45:57.374Z",
  "@version": "1",
  "message": "message {lotto={lotto-id=5, winning-numbers=[2, 45, 34, 23, 7, 5, 3], draw-date=null, winners=[{winner-id=23, numbers=[2, 45, 34, 23, 3, 5]}, {winner-id=54, numbers=[52, 3, 12, 11, 18, 22]}]}}",
  "logger_name": "example.dsl.DSLExample.main logger",
  "thread_name": "main",
  "level": "INFO",
  "level_value": 20000,
  "lotto": {
    "lotto-id": 5,
    "winning-numbers": [
      2,
      45,
      34,
      23,
      7,
      5,
      3
    ],
    "draw-date": null,
    "winners": [
      {
        "winner-id": 23,
        "numbers": [
          2,
          45,
          34,
          23,
          3,
          5
        ]
      },
      {
        "winner-id": 54,
        "numbers": [
          52,
          3,
          12,
          11,
          18,
          22
        ]
      }
    ]
  }
}