Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Debuggable IO [DIO] #849

Merged
merged 56 commits into from May 30, 2019

Conversation

@kaishh
Copy link
Member

commented May 11, 2019

ZIO Tracing's True Power, as its name suggests, is to reign supreme over the entire world!

big_1459812265_image

@iravid

This comment has been minimized.

Copy link
Member

commented May 11, 2019

@kaishh congrats! impressive work!

Is https://github.com/lihaoyi/sourcecode not used to avoid adding macros to the project?

@kaishh

This comment has been minimized.

Copy link
Member Author

commented May 11, 2019

@iravid that, and compile-time solutions cannot provide support for 3rd-party libraries, like doobie, http4s and existing code written with tagless final so we decided to go with the other way

@iravid

This comment has been minimized.

Copy link
Member

commented May 11, 2019

Cool, did not consider that! 👍

@wi101
Copy link
Contributor

left a comment

@kaishh and @jdegoes Congrats! Nice work!

@jdegoes
Copy link
Member

left a comment

Amazing work and going to be hugely helpful to real world programmers!

I have a few suggestions, my only main concern is the inescapable overhead with the wrapping (ZioFn, & friends) and maintainability overhead. Beyond that, I think the main thing I would like to see is having the tracing logic pulled out of FiberContext to simplify reasoning about the core interpreter (which can then just call into the logic class to do the heavy lifting). If you could take a crack at the easy stuff now, then we can get this merged in and deal with other issues over the coming weeks, maybe with help from other contributors.

@kaishh

This comment has been minimized.

Copy link
Member Author

commented May 30, 2019

@jdegoes
Ok, I think I've addressed everything, and moved the 2 of the bigger items to the tracker:

  • #916 - seemingly no perf gain observed from removing ZIOFn
  • #915 - detangling tracing logic while preserving JIT-friendliness might take quite some time
@kaishh

This comment has been minimized.

Copy link
Member Author

commented May 30, 2019

:shipit: ?

@kaishh

This comment has been minimized.

Copy link
Member Author

commented May 30, 2019

Final benchmarks (on a mid-tier xeon):

enabled tracing:

[info] Result "scalaz.zio.IOLeftBindBenchmark.scalazLeftBindBenchmark":
[info]   4985.133 ±(99.9%) 74.398 ops/s [Average]
[info]   (min, avg, max) = (4871.750, 4985.133, 5034.919), stdev = 49.210
[info]   CI (99.9%): [4910.735, 5059.531] (assumes normal distribution)
[info] # Run complete. Total time: 00:03:21

disabled tracing:

[info] Result "scalaz.zio.IOLeftBindBenchmark.scalazLeftBindBenchmark":
[info]   11538.118 ±(99.9%) 126.977 ops/s [Average]
[info]   (min, avg, max) = (11343.236, 11538.118, 11627.687), stdev = 83.987
[info]   CI (99.9%): [11411.141, 11665.095] (assumes normal distribution)
[info] # Run complete. Total time: 00:03:21

cats-effect IO:

[info] Result "scalaz.zio.IOLeftBindBenchmark.catsLeftBindBenchmark":
[info]   8210.027 ±(99.9%) 103.346 ops/s [Average]
[info]   (min, avg, max) = (8082.678, 8210.027, 8329.851), stdev = 68.357
[info]   CI (99.9%): [8106.681, 8313.373] (assumes normal distribution)
[info] # Run complete. Total time: 00:03:21

Tracing overhead: ~2.3x ; ~1.6x vs cats.

@goral09

This comment has been minimized.

Copy link

commented May 30, 2019

@kaishh This looks great. Can't wait to use it. It would be nice selling point to see example traces. So that people know they're not stacktraces they know and (don't) love :)

@jdegoes
Copy link
Member

left a comment

Superb! There's more work to do, but a lot of people are waiting on this, so let's get it merged in, and we can deal with remaining issues separately.

@kaishh kaishh requested a review from artempyanykh May 30, 2019

@kaishh kaishh merged commit 4f40572 into zio:master May 30, 2019

1 check passed

continuous-integration/travis-ci/pr The Travis CI build passed
Details
@kaishh

This comment has been minimized.

Copy link
Member Author

commented May 30, 2019

🎉

@iravid

This comment has been minimized.

Copy link
Member

commented May 30, 2019

finally!!

@jdegoes

This comment has been minimized.

Copy link
Member

commented May 30, 2019

giphy

kaishh added a commit that referenced this pull request May 30, 2019

Debuggable IO [DIO] (#849)
* ZIO POC #1

* Add Fiber Ancestry trace

* noticket comment mutable Spec

* Decorate Exit.Cause with traces on Fail in RTS

* Exclude Exit.Cause.trace field from equals/hashCode (???)

* wrap ZIO.const

* Fail now takes a stack trace gen

* Add Refail and decorate foreachPar/racePar APIs with it

* fixup trace for `blocking.blocking`, reduce uses for ZIO.identityFn for better traces, add a traceEffects switch

* Obey Platform-level TracingConfig. unblock scala.js version.

* re-enable inlining by fixing typo in scalac options

* enable inlining for `internal` package only (interferes with traces)

* Add inheritable tracing regions. Craft .bracket* traces, optimize global cache

* cache reflection failuires; .intern() strings after substitutions; refail in raceBoth & raceAttempt; Add AsmTracer vs. AkkaTracer benchmar; Add IODeepLeftBindBenchmark

* refactor ZTrace printing; always show FiberId; do not trace EffectTotal/With continuation if effect failed

* Always mention Execution trace / stack trace in ZTrace pretty print, even if empty.

* Use must_=== instead of throwA to ignore traces in test equality

* Move stacktraces spec to 2.12+ only

* Add Akka licence notice, move global cache under Tracer object

* fix imports

* ringbuffer fixed

* cleanups

* scalafmt

* Extend StacktracesSpec; put future trace on top in pretty print; remove FiberAncestry class;

* Fix stack traces for FlatMap's Effect* happy path; extend suite with regressions

* Add lambda wrapping for folM, catchAll and catchSome

* remove duplicate interrupt tests in RTSSpec

* Repalce Refail and trace fields with Cause.Traced!

* merge fixes

* traceExec/Stack as vals in FiberContext

* Pack tracing fields in Platform into Tracing case class

* fmt

* add newlines between ring buffer fields

* remove comment in AsmTracer

* fix TwitterSpec

* add lambda wrapping for fold/tapError/mapError/bimap/tapBothorElse/zipWith

* fmt

* restrict StacktracesSpec to 2.12-2.13 only (no dotty)

* increase timeouts in ZManagedSpec as a workaround (should use latches)

* fmt

* reposition sleep in TwitterSpec

* unused import

* tweak TwitterSpec

* Symmetric equals for Cause.Traced

* AkkaTracer -> AkkaLineNumbersTracer

* remove null in Js.PlatformLive

* remove dead code & add apache licence headers

* post-merge fixup

* Add CheckTracing

* optimize recordTrace

* add final

* add pushContinuation
@kaishh

This comment has been minimized.

Copy link
Member Author

commented May 30, 2019

@goral09
There are a couple example traces in the presentation at https://www.slideshare.net/jdegoes/error-management-future-vs-zio

Here's also an example trace from fs2 from ZIO test suite:

Fiber failed.
A checked error was not handled.
java.lang.Exception
  at scalaz.zio.interop.ZioWithFs2Spec.$anonfun$bracketFail$7(Fs2ZioSpec.scala:61)
  at scalaz.zio.ZIO$ZipRightFn.apply(ZIO.scala:2081)
  at scalaz.zio.ZIO$ZipRightFn.apply(ZIO.scala:2078)
  at scalaz.zio.internal.FiberContext.evaluateNow(FiberContext.scala:685)
  at scalaz.zio.internal.FiberContext.$anonfun$fork$1(FiberContext.scala:573)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
  at java.lang.Thread.run(Thread.java:748)

Fiber:20 was supposed to continue to:
  a future continuation at fs2.internal.Algebra$.compileLoop(Algebra.scala:349)
  a future continuation at fs2.internal.Algebra$.compile(Algebra.scala:167)
  a future continuation at scalaz.zio.ZIO.run(ZIO.scala:1026)
  a future continuation at scalaz.zio.interop.CatsEffect.bracketCase(catsjvm.scala:231)
  a future continuation at fs2.Stream$CompileOps.foldChunks(Stream.scala:3921)

Fiber:20 execution trace:
  at fs2.internal.Algebra$.compileLoop(Algebra.scala:276)
  at fs2.internal.CompileScope.interruptibleEval(CompileScope.scala:381)
  at cats.ApplicativeError.attempt(ApplicativeError.scala:68)
  at scalaz.zio.interop.ZioWithFs2Spec.bracketFail(Fs2ZioSpec.scala:61)
  at scalaz.zio.internal.FiberContext$InterruptExit$.apply(FiberContext.scala:151)
  at scalaz.zio.internal.FiberContext$InterruptExit$.apply(FiberContext.scala:142)
  at scalaz.zio.ZIO.ensuring(ZIO.scala:481)
  at scalaz.zio.ZIO.onInterrupt(ZIO.scala:543)
  at scalaz.zio.ZIO.ensuring(ZIO.scala:479)
  at scalaz.zio.internal.FiberContext$InterruptExit$.apply(FiberContext.scala:142)
  at scalaz.zio.ZIO$._IdentityFn(ZIO.scala:1992)
  at scalaz.zio.ZIOFunctions.effectAsyncInterrupt(ZIO.scala:1444)
  at scalaz.zio.ZIOFunctions.effectAsyncInterrupt(ZIO.scala:1440)
  at scalaz.zio.ZIOFunctions.effectAsyncInterrupt(ZIO.scala:1440)
  at fs2.internal.Algebra$.compileLoop(Algebra.scala:229)
  at fs2.internal.Algebra$.compileLoop(Algebra.scala:250)
  at cats.ApplicativeError.attempt(ApplicativeError.scala:68)
  at cats.ApplicativeError.attempt(ApplicativeError.scala:67)
  at fs2.internal.Algebra$.compileLoop(Algebra.scala:229)
  at fs2.internal.Algebra$.compileLoop(Algebra.scala:286)
  at fs2.internal.CompileScope.acquireResource(CompileScope.scala:168)
  at cats.effect.concurrent.Ref$SyncRef.modify(Ref.scala:253)
  at fs2.internal.CompileScope.acquireResource(CompileScope.scala:168)
  at cats.FlatMap.flatten(FlatMap.scala:41)
  at cats.effect.concurrent.Ref$SyncRef.modify(Ref.scala:253)
  at fs2.internal.CompileScope.acquireResource(CompileScope.scala:164)
  at cats.ApplicativeError.attempt(ApplicativeError.scala:68)
  at cats.ApplicativeError.attempt(ApplicativeError.scala:67)
  at scalaz.zio.ZIO.unit(ZIO.scala:905)
  at scalaz.zio.Promise$.done$extension(Promise.scala:124)
  at fs2.internal.Algebra$.compileLoop(Algebra.scala:229)
  at fs2.internal.Algebra$.compileLoop(Algebra.scala:248)
  at fs2.Stream$Compiler$.compile(Stream.scala:3858)
  at fs2.internal.CompileScope$.newRoot(CompileScope.scala:399)
  at fs2.Stream$Compiler$$anon$8.apply(Stream.scala:3863)
  at fs2.Stream$CompileOps.foldChunks(Stream.scala:3921)

Fiber:20 was spawned by:

Fiber:8 was supposed to continue to:
  a future continuation at scalaz.zio.interop.ZioWithFs2Spec.bracketFail(Fs2ZioSpec.scala:67)
  a future continuation at scalaz.zio.ZIO.timeout(ZIO.scala:950)
  a future continuation at scalaz.zio.ZIO.sandbox(ZIO.scala:1053)
  a future continuation at scalaz.zio.ZIO$.scalaz$zio$ZIO$$_succeedRight(ZIO.scala:2071)

Fiber:8 execution trace:
  at scalaz.zio.interop.ZioWithFs2Spec.bracketFail(Fs2ZioSpec.scala:57)
  at scalaz.zio.Promise$.make(Promise.scala:192)
  at scalaz.zio.interop.ZioWithFs2Spec.bracketFail(Fs2ZioSpec.scala:56)
  at scalaz.zio.Promise$.make(Promise.scala:192)
  at scalaz.zio.interop.ZioWithFs2Spec.bracketFail(Fs2ZioSpec.scala:55)
  at scalaz.zio.Promise$.make(Promise.scala:192)

Fiber:8 was spawned by:

Fiber:5 was supposed to continue to:
  a future continuation at scalaz.zio.ZIO.raceWith(ZIO.scala:279)
  a future continuation at scalaz.zio.ZIO.raceWith(ZIO.scala:285)
  a future continuation at scalaz.zio.ZIO.refailWithTrace(ZIO.scala:650)
  a future continuation at scalaz.zio.ZIO.race(ZIO.scala:223)
  a future continuation at scalaz.zio.ZIOFunctions.absolve(ZIO.scala:1462)
  a future continuation at scalaz.zio.ZIOFunctions.unsandbox(ZIO.scala:1470)

Fiber:5 execution trace:
  at scalaz.zio.ZIO.raceWith(ZIO.scala:275)
  at scalaz.zio.Ref$.make(Ref.scala:142)
  at scalaz.zio.ZIO.raceWith(ZIO.scala:274)
  at scalaz.zio.Promise$.make(Promise.scala:192)

Fiber:5 was spawned by: <empty trace>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
You can’t perform that action at this time.