Upgrade to Pro — share decks privately, control downloads, hide ads and more …

Logging without Tradeoffs

Logging without Tradeoffs

This is a little detour into the world of logging in functional
programming. In this talk we will discuss journalling, timeliness,
memory & resource usage; laugh at tutorials that scream "WRITER" then
demonstrate it with a buggy piece of code that should never go to
production; and finally build up a small library of code for logging
that isn't horribly crippled.

This was presented at ScalaSyd, May 2015.

Mark Hibberd

May 06, 2015
Tweet

More Decks by Mark Hibberd

Other Decks in Programming

Transcript

  1. Logging is the cutting, skidding, on-site processing, and loading of

    trees or logs onto trucks or skeleton cars. In forestry, the term logging is sometimes used in a narrow sense concerning the logistics of moving wood from the stump to somewhere outside the forest, usually a sawmill or a lumber yard. Wikipedia - On Logging! (i.e. can’t be wrong) (disclaimer: could actually be wrong)
  2. … logistics of moving wood from the stump to somewhere

    outside the forest, usually a sawmill or a lumber yard. Wikipedia - On Logging! (i.e. can’t be wrong) (disclaimer: could actually be wrong)
  3. &1

  4. ! 1 case class Stock(name: String) 2 3 sealed trait

    Order 4 case class Buy(stock: Stock, qty: Long) extends Order 5 case class Sell(stock: Stock, qty: Long) extends Order 6 case object Hold extends Order ! ! ! ! ! ! ! !
  5. ! 1 case class Stock(name: String) 2 3 sealed trait

    Order 4 case class Buy(stock: Stock, qty: Long) extends Order 5 case class Sell(stock: Stock, qty: Long) extends Order 6 case object Hold extends Order 7 8 case class Tick(time: Timestamp, stock: Stock, cents: Long) ! ! ! ! ! !
  6. ! 1 case class Stock(name: String) 2 3 sealed trait

    Order 4 case class Buy(stock: Stock, qty: Long) extends Order 5 case class Sell(stock: Stock, qty: Long) extends Order 6 case object Hold extends Order 7 8 case class Tick(time: Timestamp, stock: Stock, cents: Long) 9 10 case class Quanity(stock: String, qty: Long) \ ! ! !
  7. ! 1 case class Stock(name: String) 2 3 sealed trait

    Order 4 case class Buy(stock: Stock, qty: Long) extends Order 5 case class Sell(stock: Stock, qty: Long) extends Order 6 case object Hold extends Order 7 8 case class Tick(time: Timestamp, stock: Stock, cents: Long) 9 10 case class Quanity(stock: String, qty: Long) 11 12 case class Budget(cash: Long, stocks: List[Quanitity]) ! !
  8. ! 1 case class Stock(name: String) 2 3 sealed trait

    Order 4 case class Buy(stock: Stock, qty: Long) extends Order 5 case class Sell(stock: Stock, qty: Long) extends Order 6 case object Hold extends Order 7 8 case class Tick(time: Timestamp, stock: Stock, cents: Long) 9 10 case class Quanity(stock: String, qty: Long) 11 12 case class Budget(cash: Long, stocks: List[Quantity]) 13 14 case class Decision(model: Model, budget: Budget, order: Order)
  9. 1 def bot(exchange: Exchange, model: Model, budget: Budget): Error \/

    Unit = 2 exchange.next match { 3 case None => 4 5 case Some(ticks) => 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 }
  10. 1 def bot(exchange: Exchange, model: Model, budget: Budget): Error \/

    Unit = 2 exchange.next match { 3 case None => 4 Disconnected(exchange).left 5 case Some(ticks) => 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 }
  11. 1 def bot(exchange: Exchange, model: Model, budget: Budget): Error \/

    Unit = 2 exchange.next match { 3 case None => 4 Disconnected(exchange).left 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 8 9 10 11 12 13 14 15 16 17 18 19 20 }
  12. 1 def bot(exchange: Exchange, model: Model, budget: Budget): Error \/

    Unit = 2 exchange.next match { 3 case None => 4 Disconnected(exchange).left 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 check(decision) match { 8 case Some(guard) => 9 10 case None => 11 12 13 14 15 16 17 18 19 } 20 }
  13. 1 def bot(exchange: Exchange, model: Model, budget: Budget): Error \/

    Unit = 2 exchange.next match { 3 case None => 4 Disconnected(exchange).left 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 check(decision) match { 8 case Some(guard) => 9 ProgrammersTryingToLoseYourMoney(decision, guard).left 10 case None => 11 12 13 14 15 16 17 18 19 } 20 }
  14. 1 def bot(exchange: Exchange, model: Model, budget: Budget): Error \/

    Unit = 2 exchange.next match { 3 case None => 4 Disconnected(exchange).left 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 check(decision) match { 8 case Some(guard) => 9 ProgrammersTryingToLoseYourMoney(decision, guard).left 10 case None => 11 exchange.trade(decision.order, decision.budget) match { 12 case Banned(reason) => 13 14 case TradeRejected => 15 16 case TradeAccepted(budget) => 17 18 } 19 } 20 }
  15. 1 def bot(exchange: Exchange, model: Model, budget: Budget): Error \/

    Unit = 2 exchange.next match { 3 case None => 4 Disconnected(exchange).left 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 check(decision) match { 8 case Some(guard) => 9 ProgrammersTryingToLoseYourMoney(decision, guard).left 10 case None => 11 exchange.trade(decision.order, decision.budget) match { 12 case Banned(reason) => 13 BannedFor(decision, reason).left 14 case TradeRejected => 15 16 case TradeAccepted(budget) => 17 18 } 19 } 20 }
  16. 1 def bot(exchange: Exchange, model: Model, budget: Budget): Error \/

    Unit = 2 exchange.next match { 3 case None => 4 Disconnected(exchange).left 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 check(decision) match { 8 case Some(guard) => 9 ProgrammersTryingToLoseYourMoney(decision, guard).left 10 case None => 11 exchange.trade(decision.order, decision.budget) match { 12 case Banned(reason) => 13 BannedFor(decision, reason).left 14 case TradeRejected => 15 bot(exchange, decision.model, decision.budget) 16 case TradeAccepted(budget) => 17 18 } 19 } 20 }
  17. 1 def bot(exchange: Exchange, model: Model, budget: Budget): Error \/

    Unit = 2 exchange.next match { 3 case None => 4 Disconnected(exchange).left 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 check(decision) match { 8 case Some(guard) => 9 ProgrammersTryingToLoseYourMoney(decision, guard).left 10 case None => 11 exchange.trade(decision.order, decision.budget) match { 12 case Banned(reason) => 13 BannedFor(decision, reason).left 14 case TradeRejected => 15 bot(exchange, decision.model, decision.budget) 16 case TradeAccepted(budget) => 17 bot(exchange, decision.model, budget) 18 } 19 } 20 }
  18. ! 1 def decide(seed: Model, ticks: List[Tick], budget: Budget): Decision

    = { 2 val model = seed.update(ticks, budget) 3 4 5 6 7 8 9 10 }
  19. ! 1 def decide(seed: Model, ticks: List[Tick], budget: Budget): Decision

    = { 2 val model = seed.update(ticks, budget) 3 val predictions = model.predictions 4 5 6 7 8 9 10 }
  20. ! 1 def decide(seed: Model, ticks: List[Tick], budget: Budget): Decision

    = { 2 val model = seed.update(ticks, budget) 3 val predictions = model.predictions 4 val offer = 5 predictions 6 .sortBy(p => -1 * p.confidence * p.score) 7 .map(_.offer) 8 .head 9 10 }
  21. ! 1 def decide(seed: Model, ticks: List[Tick], budget: Budget): Decision

    = { 2 val model = seed.update(ticks, budget) 3 val predictions = model.predictions 4 val offer = 5 predictions 6 .sortBy(p => -1 * p.confidence * p.score) 7 .map(_.offer) 8 .head 9 Decision(model, budget, offer) 10 }
  22. ! 1 def bot(exchange: Exchange, model: Model, budget: Budget): Error

    \/ Unit = 2 exchange.next match { 3 case None => 4 Disconnected(exchange).left 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 check(decision) match { 8 case Some(guard) => 9 ProgrammersTryingToLoseYourMoney(decision, guard).left 10 case None => 11 exchange.trade(decision.order, decision.budget) match { 12 case Banned(reason) => 13 BannedFor(decision, reason).left 14 case TradeRejected => 15 bot(exchange, decision.model, decision.budget) 16 case TradeAccepted(budget) => 17 bot(exchange, decision.model, budget) 18 } 19 } 20 }
  23. ! 1 def bot(exchange: Exchange, model: Model, budget: Budget): EitherT[IO,

    Error, Unit] = 2 exchange.next.flatMap({ 3 case None => 4 EitherT.left(Diconnected(exchange)) 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 check(decision) match { 8 case Some(guard) => 9 EitherT.left(ProgrammersTryingToLoseYourMoney(decision, guard)) 10 case None => 11 exchange.trade(decision.order, decision.budget) match { 12 case Banned(reason) => 13 EitherT.left(BannedFor(decision, reason)) 14 case TradeRejected => 15 bot(exchange, decision.model, decision.budget) 16 case TradeAccepted(budget) => 17 bot(exchange, decision.model, budget) 18 } 19 } 20 })
  24. ! 1 def bot(exchange: Exchange, model: Model, budget: Budget): EitherT[IO,

    Error, Unit] = 2 exchange.next.flatMap({ 3 case None => 4 EitherT.left(Diconnected(exchange)) 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 check(decision) match { 8 case Some(guard) => 9 EitherT.left(ProgrammersTryingToLoseYourMoney(decision, guard)) 10 case None => 11 exchange.trade(decision.order, decision.budget) match { 12 case Banned(reason) => 13 EitherT.left(BannedFor(decision, reason)) 14 case TradeRejected => 15 bot(exchange, decision.model, decision.budget) 16 case TradeAccepted(budget) => 17 bot(exchange, decision.model, budget) 18 } 19 } 20 })
  25. ! 1 def bot(exchange: Exchange, model: Model, budget: Budget): EitherT[IO,

    Error, Unit] = 2 exchange.next.flatMap({ 3 case None => 4 EitherT.left(Diconnected(exchange)) 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 check(decision) match { 8 case Some(guard) => 9 EitherT.left(ProgrammersTryingToLoseYourMoney(decision, guard)) 10 case None => 11 exchange.trade(decision.order, decision.budget) match { 12 case Banned(reason) => 13 EitherT.left(BannedFor(decision, reason)) 14 case TradeRejected => 15 bot(exchange, decision.model, decision.budget) 16 case TradeAccepted(budget) => 17 bot(exchange, decision.model, budget) 18 } 19 } 20 }) ! avoid it
  26. ! 1 sealed trait Error 2 3 case class BannedFor(

    4 decision: Decision 5 , reason: Reason 6 ) extends Error 7 8 case object Disconnected 9 extends Error 10 11 case class ProgrammersTryingToLoseYourMoney( 12 decision: Decision 13 , check: Check 14 ) extends Error !
  27. (,)

  28. ! 1 def decide(seed: Model, ticks: List[Tick], budget: Budget): Decision

    = { 2 val model = seed.update(ticks, budget) 3 val predictions = model.predictions 4 val offer = 5 predictions 6 .sortBy(p => -1 * p.confidence * p.score) 7 .map(_.offer) 8 .head 9 Decision(model, budget, offer) 10 }
  29. ! 1 def decide(s: Model, t: List[Tick], b: Budget): Writer[Log,

    Decision] = { 2 val model = seed.update(ticks, budget) 3 val predictions = model.predictions 4 val offer = 5 predictions 6 .sortBy(p => -1 * p.confidence * p.score) 7 .map(_.offer) 8 .head 9 Decision(model, budget, offer) <++ (“all predictions: ” + predictions) 10 }
  30. ! 1 def bot(exchange: Exchange, model: Model, budget: Budget): EitherT[IO,

    Error, Unit] = 2 exchange.next.flatMap({ 3 case None => 4 EitherT.left(Diconnected(exchange)) 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 check(decision) match { 8 case Some(guard) => 9 EitherT.left(ProgrammersTryingToLoseYourMoney(decision, guard)) 10 case None => 11 exchange.trade(decision.order, decision.budget) match { 12 case Banned(reason) => 13 EitherT.left(BannedFor(decision, reason)) 14 case TradeRejected => 15 bot(exchange, decision.model, decision.budget) 16 case TradeAccepted(budget) => 17 bot(exchange, decision.model, budget) 18 } 19 } 20 })
  31. ! 1 def bot(exchange: Exchange, model: Model, budget: Budget): EitherT[IO,

    Error, Unit] = 2 exchange.next.flatMap({ 3 case None => 4 EitherT.left(Diconnected(exchange)) 5 case Some(ticks) => 6 val decision = decide(model, ticks, budget) 7 check(decision) match { 8 case Some(guard) => 9 EitherT.left(ProgrammersTryingToLoseYourMoney(decision, guard)) 10 case None => 11 exchange.trade(decision.order, decision.budget) match { 12 case Banned(reason) => 13 EitherT.left(BannedFor(decision, reason)) 14 case TradeRejected => 15 bot(exchange, decision.model, decision.budget) 16 case TradeAccepted(budget) => 17 bot(exchange, decision.model, budget) 18 } 19 } 20 }) ! fail at it
  32. 2 def bot(exchange: Exchange, model: Model, budget: Budget): EitherT[IO, Error,

    Unit] = 3 exchange.next.flatMap({ 4 case None => 5 EitherT.left(Diconnected(exchange)) 6 case Some(ticks) => 7 val decision = decide(model, ticks, budget) 8 println("got ticks: " + ticks.size) 9 check(decision) match { 10 case Some(guard) => 11 EitherT.left(ProgrammersTryingToLoseYourMoney(decision, guard)) 12 case None => 13 exchange.trade(decision.order, decision.budget) match { 14 case Banned(reason) => 15 EitherT.left(BannedFor(decision, reason)) 16 case TradeRejected => 17 println("trade-rejected: " + decision) 18 bot(exchange, decision.model, decision.budget) 19 case TradeAccepted(budget) => 20 bot(exchange, decision.model, budget) 21 } 22 } 23 }) ! fail at it
  33. 2 def bot(exchange: Exchange, model: Model, budget: Budget): EitherT[IO, Error,

    Unit] = 3 exchange.next.flatMap({ 4 case None => 5 EitherT.left(Diconnected(exchange)) 6 case Some(ticks) => 7 val decision = decide(model, ticks, budget) 8 putStrLn("got ticks: " + ticks.size).liftIO >> ( 9 check(decision) match { 10 case Some(guard) => 11 EitherT.left(ProgrammersTryingToLoseYourMoney(decision, guard)) 12 case None => 13 exchange.trade(decision.order, decision.budget) match { 14 case Banned(reason) => 15 EitherT.left(BannedFor(decision, reason)) 16 case TradeRejected => 17 putStrLn("trade-rejected: " + decision).liftIO >> 18 bot(exchange, decision.model, decision.budget) 19 case TradeAccepted(budget) => 20 bot(exchange, decision.model, budget) 21 } 22 }) 23 }) ! fail at it (again)
  34. ! def bot( e: Exchange , m: Model , b:

    Budget , t: Trace ): EitherT[IO, Error, Unit]
  35. ! def bot( e: Exchange , m: Model , b:

    Budget , t: Trace ): EitherT[IO, Error, Unit]
  36. ! type App[A] = ReaderT[EitherT[IO, _], Trace[IO], A] ! def

    bot( e: Exchange , m: Model , b: Budget ): App[IO, Error, Unit]
  37. ! def bot( e: Exchange , m: Model , b:

    Budget , t: Trace ): EitherT[IO, Error, Unit]
  38. 2 def bot(e: Exchange, m: Model, b: Budget, t: Trace):

    EitherT[IO, Error, Unit] 3 exchange.next.flatMap({ 4 case None => 5 EitherT.left(Diconnected(exchange)) 6 case Some(ticks) => 7 val decision = decide(model, ticks, budget) 8 t.trace(“got ticks: " + ticks.size).liftIO >> ( 9 check(decision) match { 10 case Some(guard) => 11 EitherT.left(ProgrammersTryingToLoseYourMoney(decision, guard)) 12 case None => 13 exchange.trade(decision.order, decision.budget) match { 14 case Banned(reason) => 15 EitherT.left(BannedFor(decision, reason)) 16 case TradeRejected => 17 t.trace(“trade-rejected: " + decision).liftIO >> 18 bot(exchange, decision.model, decision.budget) 19 case TradeAccepted(budget) => 20 bot(exchange, decision.model, budget) 21 } 22 }) 23 })
  39. ! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,

    b: Budget ): EitherT[F, Error, Unit] ! bot[IO]( real , model , budget ): EitherT[IO, Error, Unit] ! bot[Option]( memory , model , budget ): EitherT[Option, Error, Unit]
  40. ! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,

    b: Budget ): EitherT[F, Error, Unit] ! bot[IO]( real , model , budget ): IO[Error \/ Unit] ! bot[Option]( memory , model , budget ): Option[Error \/ Unit]
  41. 1 sealed trait Log 2 3 case class Received( 4

    ticks: List[Tick] 5 ) extends Error 6 7 case class Reject( 8 decision: Decision 9 ) 10 11 case class Accepted( 12 decision: Decision 13 ) 14 15 case class Prediction ( 16 predictions: NonEmptyList[Prediction] 17 , selected: Offer 18 )
  42. ! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,

    b: Budget , t: Trace[F, Log] ): EitherT[F, Error, Unit]
  43. ! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,

    b: Budget , t: Trace[F, Log] ): EitherT[F, Error, Unit]
  44. ! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,

    b: Budget , t: Trace[EitherT[F, _, ?], Log] ): EitherT[F, Error, Unit]
  45. ! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,

    b: Budget , t: Trace[EitherT[F, _, ?], Log] ): EitherT[F, Error, Unit]
  46. ! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,

    b: Budget , t: Trace[EitherT[F, _, ?], Log] ): EitherT[F, Error, Unit]
  47. 2 type Trace[F[_], A] = 3 ReaderT[F, A, Unit] 4

    5 type Traceable[F[_], A, B] = 6 ReaderT[F, Trace[F], A]
  48. ! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,

    b: Budget ): Traceable[EitherT[F, Error, ?], Log, Unit]
  49. 2 type Trace[F[_], A] = 3 ReaderT[F, A, Unit] 4

    5 type Traceable[F[_], A, B] = 6 ReaderT[F, Trace[F], A] 7 8 type Bot[F[_], A] = 9 Traceable[F[_], Log, A]
  50. ! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,

    b: Budget ): Bot[EitherT[F, Error, ?], Unit]
  51. 2 type Trace[F[_], A] = 3 ReaderT[F, A, Unit] 4

    5 type Traceable[F[_], A, B] = 6 ReaderT[F, Trace[F], A] 7 8 type Bot[F[_], A] = 9 Traceable[F[_], Log, A]
  52. ! 1 def decide[F[_]](s: Model, t: List[Tick], b: Budget): Bot[F,

    Decision] = { 2 val model = seed.update(ticks, budget) 3 val predictions = model.predictions 4 val offer = 5 predictions 6 .sortBy(p => -1 * p.confidence * p.score) 7 .map(_.offer) 8 .head 9 log(Prediction(prediction, off)).as( 10 Decision(model, budget, offer)) 11 }
  53. 2 def bot(e: Exchange, m: Model, b: Budget): Bot[EitherT[F, Error

    ?], Unit] = 3 exchange.next.flatMap({ 4 case None => 5 EitherT.left(Diconnected(exchange)).lift 6 case Some(ticks) => 7 val decision = decide(model, ticks, budget).lift 8 log(Received(ticks)) >> ( 9 check(decision) match { 10 case Some(guard) => 11 EitherT.left(ProgrammersTryingToLoseYourMoney(decision, guard)).lift 12 case None => 13 exchange.trade(decision.order, decision.budget) match { 14 case Banned(reason) => 15 EitherT.left(BannedFor(decision, reason)).lift 16 case TradeRejected => 17 log(Rejected(decision)) >> 18 bot(exchange, decision.model, decision.budget) 19 case TradeAccepted(budget) => 20 bot(exchange, decision.model, budget) 21 } 22 }) 23 })
  54. 1 2 def writer[F[_]: Applicative, A]: Trace[WriterT[F, Vector[A], ?]] =

    3 Trace(a => WriterT.tell(a)) 4 5 def stream[A](out: java.io.PrintStream, show: A => String) : Trace[IO, A] = 6 Trace(a => IO { out.println(show(a)) }) 7 8 def out[A](show: A => String): Trace[IO, A] = 9 stream(Console.out) 10 11 def err[A](show: A => String): Trace[IO, A] = 12 stream(Console.err) 13 14 def noop[F[_]: Applicative, A]: Trace[F, A] = 15 Trace(_ => ().pure[F]) 16 17 def hoistEither[F[_], A](t: Trace[F, A]): Trace[EitherT[F, _, A]] = 18 ??? 19 20 def io[F[_], A](t: Trace[WriterT[F, Vector[A], ?], A]):Trace[IO, A] = 22 ???
  55. 2 val d1: Decision = 3 decide(seed, ticks, budget).run(noop[Id, Log])

    4 5 val d2: (Vector[Log], Decision) = 6 decide(seed, ticks, budget).run(writer[Log]).run 7 8 val d3: IO[Decision] = 9 decide(seed, ticks, budget).run(out(render)).run
  56. 2 type Trace[F[_], A] = 3 ReaderT[F, A, Unit] 4

    5 type Traceable[F[_], A, B] = 6 ReaderT[F, Trace[F], A] 7 8 type Bot[F[_], A] = 9 Traceable[F[_], Log, A]
  57. 1 2 def writer[F[_]: Applicative, A]: Trace[WriterT[F, Vector[A], ?]] =

    3 Trace(a => WriterT.tell(a)) 4 5 def stream[A](out: java.io.PrintStream, show: A => String) : Trace[IO, A] = 6 Trace(a => IO { out.println(show(a)) }) 7 8 def out[A](show: A => String): Trace[IO, A] = 9 stream(Console.out) 10 11 def err[A](show: A => String): Trace[IO, A] = 12 stream(Console.err) 13 14 def noop[F[_]: Applicative, A]: Trace[F, A] = 15 Trace(_ => ().pure[F]) 16 17 def hoistEither[F[_], A](t: Trace[F, A]): Trace[EitherT[F, _, A]] = 18 ??? 19 20 def io[F[_], A](t: Trace[WriterT[F, Vector[A], ?], A]):Trace[IO, A] = 22 ???
  58. 3 case class Trace[F[_], A]( 4 trace: A => F[Unit]

    5 , hoist: Trace[WriterT[F, Vector[A], ?], A] 6 )