Share
Embed
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
Transcript
95 slides
-
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) -
… 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) -
! 1 case class Stock(name: String) ! ! ! !
! ! ! ! ! ! ! ! -
! 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 ! ! ! ! ! ! ! ! -
! 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) ! ! ! ! ! ! -
! 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) \ ! ! ! -
! 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]) ! ! -
! 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) -
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 } -
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 } -
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 } -
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 } -
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 } -
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 } -
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 } -
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 } -
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 } -
! 1 def decide(seed: Model, ticks: List[Tick], budget: Budget): Decision
= { 2 3 4 5 6 7 8 9 10 } -
! 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 } -
! 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 } -
! 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 } -
! 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 } -
! 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 } -
! 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 }) -
! 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 }) -
! 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 -
! 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 ! -
! 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 } -
! 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 } -
! 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 }) -
! 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 -
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 -
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) -
! def bot( e: Exchange , m: Model , b:
Budget , t: Trace ): EitherT[IO, Error, Unit] -
! def bot( e: Exchange , m: Model , b:
Budget , t: Trace ): EitherT[IO, Error, Unit] -
! type App[A] = ReaderT[EitherT[IO, _], Trace[IO], A] ! def
bot( e: Exchange , m: Model , b: Budget ): App[IO, Error, Unit] -
! def bot( e: Exchange , m: Model , b:
Budget , t: Trace ): EitherT[IO, Error, Unit] -
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 }) -
! 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] -
! 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] -
3 case class Trace[F[_], A](trace: A => F[Unit]) ! !
avoid strings -
3 case class Trace[F[_], A](trace: A => F[Unit]) ! !
seen this before? -
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 ) -
! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,
b: Budget , t: Trace[F, Log] ): EitherT[F, Error, Unit] -
! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,
b: Budget , t: Trace[F, Log] ): EitherT[F, Error, Unit] -
! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,
b: Budget , t: Trace[EitherT[F, _, ?], Log] ): EitherT[F, Error, Unit] -
! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,
b: Budget , t: Trace[EitherT[F, _, ?], Log] ): EitherT[F, Error, Unit] -
! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,
b: Budget , t: Trace[EitherT[F, _, ?], Log] ): EitherT[F, Error, Unit] -
2 type Trace[F[_], A] = 3 ReaderT[F, A, Unit] 4
5 type Traceable[F[_], A, B] = 6 ReaderT[F, Trace[F], A] -
! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,
b: Budget ): Traceable[EitherT[F, Error, ?], Log, Unit] -
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] -
! def bot[F[_]: Monad]( e: Exchange[F] , m: Model ,
b: Budget ): Bot[EitherT[F, Error, ?], Unit] -
! def decide( seed: Model , ticks: List[Tick] , budget:
Budget ): Writer[Log, Decision] -
! def decide[F[_]: Monad]( seed: Model , ticks: List[Tick] ,
budget: Budget ): Bot[F, Decision] -
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] -
! 1 def log[F[_]](message: A): Traceable[F, A, Unit] = 2
ReaderT(t => t.trace(message)) -
! 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 } -
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 }) -
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 ??? -
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 -
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] -
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 ??? -
3 case class Trace[F[_], A]( 4 trace: A => F[Unit]
5 , hoist: Trace[WriterT[F, Vector[A], ?], A] 6 )